You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/05/23 15:31:02 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/ibm-j9-jdk7) - Build #
5793 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/5793/
Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
1 tests failed.
REGRESSION: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch
Error Message:
Server at http://127.0.0.1:42260/_agk/onenodecollectioncore returned non ok status:404, message:Can not find: /_agk/onenodecollectioncore/update
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:42260/_agk/onenodecollectioncore returned non ok status:404, message:Can not find: /_agk/onenodecollectioncore/update
at __randomizedtesting.SeedInfo.seed([1F1F07593A8E84EF:9EF989414DD1E4D3]: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 9185 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4] 2> 33245 T140 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_agk/
[junit4:junit4] 2> 33249 T140 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1369314675009
[junit4:junit4] 2> 33250 T140 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 33254 T141 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 33354 T140 oasc.ZkTestServer.run start zk server on port:58582
[junit4:junit4] 2> 33357 T140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 33369 T147 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bc58dd6d name:ZooKeeperConnection Watcher:127.0.0.1:58582 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 33371 T140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 33372 T140 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 33376 T140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 33378 T149 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@903d9247 name:ZooKeeperConnection Watcher:127.0.0.1:58582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 33378 T140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 33379 T140 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 33382 T140 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 33385 T140 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 33387 T140 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 33391 T140 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> 33392 T140 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 33399 T140 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> 33400 T140 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 33405 T140 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> 33407 T140 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 33411 T140 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> 33412 T140 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 33415 T140 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> 33415 T140 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 33419 T140 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> 33420 T140 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 33422 T140 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> 33423 T140 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 33425 T140 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> 33426 T140 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 33429 T140 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> 33430 T140 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 33560 T140 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 33565 T140 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41824
[junit4:junit4] 2> 33567 T140 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 33568 T140 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 33569 T140 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1369314675193
[junit4:junit4] 2> 33570 T140 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1369314675193/solr.xml
[junit4:junit4] 2> 33571 T140 oasc.CoreContainer.<init> New CoreContainer -2135521897
[junit4:junit4] 2> 33572 T140 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1369314675193/'
[junit4:junit4] 2> 33573 T140 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1369314675193/'
[junit4:junit4] 2> 33634 T140 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 33635 T140 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 33636 T140 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 33637 T140 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 33638 T140 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 33639 T140 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 33640 T140 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 33641 T140 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 33641 T140 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 33642 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 33652 T140 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 33653 T140 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58582/solr
[junit4:junit4] 2> 33654 T140 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 33655 T140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 33658 T160 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@137501e3 name:ZooKeeperConnection Watcher:127.0.0.1:58582 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 33659 T140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 33661 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 33672 T140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 33674 T162 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@975b09e7 name:ZooKeeperConnection Watcher:127.0.0.1:58582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 33674 T140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 33676 T140 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 33678 T140 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 33681 T140 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 33682 T140 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41824__agk
[junit4:junit4] 2> 33683 T140 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:41824__agk
[junit4:junit4] 2> 33686 T140 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 33690 T140 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 33692 T140 oasc.Overseer.start Overseer (id=89739406541783043-127.0.0.1:41824__agk-n_0000000000) starting
[junit4:junit4] 2> 33695 T140 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 33699 T164 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 33700 T140 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 33703 T140 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 33705 T140 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 33707 T163 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 33709 T165 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1369314675193/collection1
[junit4:junit4] 2> 33710 T165 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 33710 T165 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 33711 T165 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 33712 T165 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1369314675193/collection1/'
[junit4:junit4] 2> 33713 T165 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1369314675193/collection1/lib/README' to classloader
[junit4:junit4] 2> 33713 T165 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1369314675193/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 33739 T165 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 33770 T165 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 33774 T165 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 33779 T165 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 34185 T165 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 34193 T165 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 34196 T165 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 34211 T165 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 34217 T165 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 34227 T165 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 34230 T165 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 34231 T165 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 34232 T165 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 34235 T165 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 34236 T165 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 34237 T165 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 34238 T165 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1369314675193/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/control/data/
[junit4:junit4] 2> 34239 T165 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2322e1d0
[junit4:junit4] 2> 34240 T165 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 34241 T165 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/control/data
[junit4:junit4] 2> 34241 T165 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/control/data/index/
[junit4:junit4] 2> 34241 T165 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 34242 T165 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/control/data/index
[junit4:junit4] 2> 34244 T165 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@52f17c96 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6b99a68f),segFN=segments_1,generation=1}
[junit4:junit4] 2> 34244 T165 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 34246 T165 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 34247 T165 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 34247 T165 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 34248 T165 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 34249 T165 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 34249 T165 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 34249 T165 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 34250 T165 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 34250 T165 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 34252 T165 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 34254 T165 oass.SolrIndexSearcher.<init> Opening Searcher@15c7d168 main
[junit4:junit4] 2> 34254 T165 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/control/data/tlog
[junit4:junit4] 2> 34255 T165 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 34255 T165 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 34261 T166 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15c7d168 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 34263 T165 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 34263 T165 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 35214 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 35216 T163 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:41824/_agk",
[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:41824__agk",
[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> 35216 T163 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 35223 T163 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 35234 T162 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> 35265 T165 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 35266 T165 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:41824/_agk collection:control_collection shard:shard1
[junit4:junit4] 2> 35270 T165 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 35284 T165 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 35297 T165 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 35300 T165 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 35301 T165 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 35302 T165 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:41824/_agk/collection1/
[junit4:junit4] 2> 35302 T165 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 35303 T165 oasc.SyncStrategy.syncToMe http://127.0.0.1:41824/_agk/collection1/ has no replicas
[junit4:junit4] 2> 35303 T165 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:41824/_agk/collection1/
[junit4:junit4] 2> 35303 T165 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 36741 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 36755 T162 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> 36811 T165 oasc.ZkController.register We are http://127.0.0.1:41824/_agk/collection1/ and leader is http://127.0.0.1:41824/_agk/collection1/
[junit4:junit4] 2> 36812 T165 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:41824/_agk
[junit4:junit4] 2> 36812 T165 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 36813 T165 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 36814 T165 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 36817 T165 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 36819 T140 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 36821 T140 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 36836 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 36846 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 36848 T140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 36850 T169 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6bf3a499 name:ZooKeeperConnection Watcher:127.0.0.1:58582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 36850 T140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 36851 T140 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 36855 T140 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 36942 T140 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 36944 T140 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44201
[junit4:junit4] 2> 36945 T140 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 36946 T140 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 36947 T140 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1369314678614
[junit4:junit4] 2> 36947 T140 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1369314678614/solr.xml
[junit4:junit4] 2> 36948 T140 oasc.CoreContainer.<init> New CoreContainer -176917460
[junit4:junit4] 2> 36948 T140 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1369314678614/'
[junit4:junit4] 2> 36949 T140 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1369314678614/'
[junit4:junit4] 2> 36988 T140 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 36989 T140 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 36990 T140 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 36990 T140 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 36991 T140 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 36992 T140 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 36993 T140 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 36993 T140 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 36994 T140 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 36995 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 37005 T140 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 37006 T140 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58582/solr
[junit4:junit4] 2> 37006 T140 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 37008 T140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 37009 T180 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8c39793d name:ZooKeeperConnection Watcher:127.0.0.1:58582 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 37009 T140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 37011 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 37026 T140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 37028 T182 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1479c23b name:ZooKeeperConnection Watcher:127.0.0.1:58582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 37029 T140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 37035 T140 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 38040 T140 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44201__agk
[junit4:junit4] 2> 38041 T140 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44201__agk
[junit4:junit4] 2> 38044 T169 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 38044 T162 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 38044 T162 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> 38044 T182 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 38049 T183 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1369314678614/collection1
[junit4:junit4] 2> 38049 T183 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 38050 T183 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 38050 T183 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 38051 T183 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1369314678614/collection1/'
[junit4:junit4] 2> 38052 T183 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1369314678614/collection1/lib/README' to classloader
[junit4:junit4] 2> 38053 T183 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1369314678614/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 38078 T183 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 38114 T183 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 38115 T183 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 38120 T183 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 38262 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 38263 T163 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:41824/_agk",
[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:41824__agk",
[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> 38267 T182 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> 38267 T169 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> 38267 T162 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> 38461 T183 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 38470 T183 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 38473 T183 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 38486 T183 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 38490 T183 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 38494 T183 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 38495 T183 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 38495 T183 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 38495 T183 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 38496 T183 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 38497 T183 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 38497 T183 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 38498 T183 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1369314678614/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty1/
[junit4:junit4] 2> 38498 T183 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2322e1d0
[junit4:junit4] 2> 38499 T183 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 38499 T183 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty1
[junit4:junit4] 2> 38500 T183 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty1/index/
[junit4:junit4] 2> 38500 T183 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 38500 T183 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty1/index
[junit4:junit4] 2> 38502 T183 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4dce7692 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7051b403),segFN=segments_1,generation=1}
[junit4:junit4] 2> 38503 T183 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 38505 T183 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 38505 T183 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 38506 T183 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 38507 T183 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 38507 T183 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 38508 T183 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 38508 T183 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 38509 T183 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 38509 T183 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 38511 T183 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 38512 T183 oass.SolrIndexSearcher.<init> Opening Searcher@c5e200c9 main
[junit4:junit4] 2> 38513 T183 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty1/tlog
[junit4:junit4] 2> 38514 T183 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 38514 T183 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 38521 T184 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c5e200c9 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 38525 T183 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 38525 T183 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 39771 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 39772 T163 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:44201/_agk",
[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:44201__agk",
[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> 39772 T163 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 39772 T163 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 39776 T169 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> 39777 T162 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> 39777 T182 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> 40527 T183 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 40528 T183 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44201/_agk collection:collection1 shard:shard1
[junit4:junit4] 2> 40529 T183 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 40539 T183 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 40543 T183 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 40543 T183 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 40544 T183 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44201/_agk/collection1/
[junit4:junit4] 2> 40545 T183 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 40546 T183 oasc.SyncStrategy.syncToMe http://127.0.0.1:44201/_agk/collection1/ has no replicas
[junit4:junit4] 2> 40546 T183 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44201/_agk/collection1/
[junit4:junit4] 2> 40547 T183 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 41282 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 41297 T162 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> 41297 T169 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> 41297 T182 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> 41307 T183 oasc.ZkController.register We are http://127.0.0.1:44201/_agk/collection1/ and leader is http://127.0.0.1:44201/_agk/collection1/
[junit4:junit4] 2> 41308 T183 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44201/_agk
[junit4:junit4] 2> 41309 T183 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 41310 T183 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 41310 T183 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 41313 T183 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 41317 T140 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 41318 T140 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 41320 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 41434 T140 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 41436 T140 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:42260
[junit4:junit4] 2> 41437 T140 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 41438 T140 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 41438 T140 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1369314683095
[junit4:junit4] 2> 41439 T140 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1369314683095/solr.xml
[junit4:junit4] 2> 41439 T140 oasc.CoreContainer.<init> New CoreContainer -870445779
[junit4:junit4] 2> 41440 T140 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1369314683095/'
[junit4:junit4] 2> 41441 T140 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1369314683095/'
[junit4:junit4] 2> 41482 T140 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 41483 T140 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 41483 T140 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 41484 T140 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 41485 T140 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 41485 T140 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 41486 T140 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 41487 T140 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 41487 T140 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 41488 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 41495 T140 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 41495 T140 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58582/solr
[junit4:junit4] 2> 41496 T140 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 41497 T140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 41499 T196 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e0b7d7b name:ZooKeeperConnection Watcher:127.0.0.1:58582 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 41499 T140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 41501 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 41507 T140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 41509 T198 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a1d9e00 name:ZooKeeperConnection Watcher:127.0.0.1:58582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 41509 T140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 41512 T140 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 42515 T140 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42260__agk
[junit4:junit4] 2> 42516 T140 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42260__agk
[junit4:junit4] 2> 42518 T169 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> 42518 T162 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 42518 T182 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 42519 T198 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 42519 T182 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> 42519 T162 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> 42524 T199 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1369314683095/collection1
[junit4:junit4] 2> 42524 T199 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 42524 T169 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 42525 T199 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 42525 T199 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 42526 T199 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1369314683095/collection1/'
[junit4:junit4] 2> 42527 T199 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1369314683095/collection1/lib/README' to classloader
[junit4:junit4] 2> 42528 T199 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1369314683095/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 42559 T199 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 42590 T199 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 42591 T199 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 42596 T199 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 42804 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 42806 T163 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:44201/_agk",
[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:44201__agk",
[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> 42810 T162 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> 42810 T182 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> 42811 T169 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> 42811 T198 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> 42953 T199 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 42961 T199 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 42963 T199 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 42975 T199 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 42979 T199 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 42983 T199 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 42984 T199 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 42984 T199 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 42985 T199 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 42986 T199 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 42986 T199 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 42986 T199 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 42987 T199 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1369314683095/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty2/
[junit4:junit4] 2> 42987 T199 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2322e1d0
[junit4:junit4] 2> 42988 T199 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 42989 T199 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty2
[junit4:junit4] 2> 42989 T199 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty2/index/
[junit4:junit4] 2> 42989 T199 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 42990 T199 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty2/index
[junit4:junit4] 2> 42991 T199 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@97560f1e lockFactory=org.apache.lucene.store.NativeFSLockFactory@14ebc68a),segFN=segments_1,generation=1}
[junit4:junit4] 2> 42992 T199 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 42994 T199 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 42995 T199 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 42995 T199 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 42996 T199 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 42997 T199 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 42997 T199 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 42998 T199 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 42998 T199 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 42999 T199 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 43000 T199 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 43002 T199 oass.SolrIndexSearcher.<init> Opening Searcher@a2353a79 main
[junit4:junit4] 2> 43003 T199 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty2/tlog
[junit4:junit4] 2> 43003 T199 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 43004 T199 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 43010 T200 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a2353a79 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 43013 T199 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 43013 T199 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 44316 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 44319 T163 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:42260/_agk",
[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:42260__agk",
[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> 44320 T163 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 44320 T163 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 44329 T162 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> 44329 T182 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> 44329 T198 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> 44329 T169 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> 45015 T199 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 45016 T199 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42260/_agk collection:collection1 shard:shard2
[junit4:junit4] 2> 45018 T199 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 45027 T199 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 45031 T199 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 45031 T199 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 45032 T199 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:42260/_agk/collection1/
[junit4:junit4] 2> 45033 T199 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 45034 T199 oasc.SyncStrategy.syncToMe http://127.0.0.1:42260/_agk/collection1/ has no replicas
[junit4:junit4] 2> 45034 T199 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:42260/_agk/collection1/
[junit4:junit4] 2> 45035 T199 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 45835 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 45843 T162 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> 45843 T169 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> 45843 T182 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> 45843 T198 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> 45896 T199 oasc.ZkController.register We are http://127.0.0.1:42260/_agk/collection1/ and leader is http://127.0.0.1:42260/_agk/collection1/
[junit4:junit4] 2> 45896 T199 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42260/_agk
[junit4:junit4] 2> 45897 T199 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 45897 T199 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 45898 T199 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 45900 T199 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 45902 T140 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 45903 T140 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 45910 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 46008 T140 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 46010 T140 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46223
[junit4:junit4] 2> 46011 T140 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 46012 T140 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 46013 T140 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1369314687678
[junit4:junit4] 2> 46013 T140 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1369314687678/solr.xml
[junit4:junit4] 2> 46014 T140 oasc.CoreContainer.<init> New CoreContainer -1044714278
[junit4:junit4] 2> 46014 T140 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1369314687678/'
[junit4:junit4] 2> 46015 T140 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1369314687678/'
[junit4:junit4] 2> 46061 T140 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 46062 T140 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 46062 T140 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 46063 T140 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 46064 T140 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 46065 T140 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 46065 T140 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 46066 T140 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 46066 T140 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 46067 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 46077 T140 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 46077 T140 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58582/solr
[junit4:junit4] 2> 46078 T140 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 46079 T140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 46081 T212 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a76215 name:ZooKeeperConnection Watcher:127.0.0.1:58582 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 46081 T140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 46083 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 46092 T140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 46096 T214 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a356fb9 name:ZooKeeperConnection Watcher:127.0.0.1:58582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 46096 T140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 46099 T140 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 47103 T140 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46223__agk
[junit4:junit4] 2> 47105 T140 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46223__agk
[junit4:junit4] 2> 47107 T198 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> 47107 T169 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> 47108 T182 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 47108 T162 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 47108 T182 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> 47109 T162 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> 47108 T214 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 47110 T198 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 47110 T169 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 47115 T215 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1369314687678/collection1
[junit4:junit4] 2> 47121 T215 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 47122 T215 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 47122 T215 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 47123 T215 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1369314687678/collection1/'
[junit4:junit4] 2> 47124 T215 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1369314687678/collection1/lib/README' to classloader
[junit4:junit4] 2> 47125 T215 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1369314687678/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 47153 T215 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 47197 T215 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 47199 T215 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 47207 T215 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 47363 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 47365 T163 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:42260/_agk",
[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:42260__agk",
[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> 47370 T162 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> 47370 T214 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> 47370 T198 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> 47370 T169 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> 47370 T182 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> 47728 T215 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 47747 T215 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 47751 T215 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 47779 T215 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 47785 T215 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 47796 T215 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 47802 T215 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 47802 T215 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 47803 T215 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 47806 T215 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 47807 T215 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 47808 T215 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 47808 T215 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1369314687678/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3/
[junit4:junit4] 2> 47809 T215 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2322e1d0
[junit4:junit4] 2> 47810 T215 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 47811 T215 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3
[junit4:junit4] 2> 47811 T215 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3/index/
[junit4:junit4] 2> 47812 T215 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 47812 T215 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3/index
[junit4:junit4] 2> 47815 T215 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@bf8e473f lockFactory=org.apache.lucene.store.NativeFSLockFactory@387ba27a),segFN=segments_1,generation=1}
[junit4:junit4] 2> 47816 T215 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 47819 T215 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 47820 T215 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 47821 T215 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 47822 T215 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 47823 T215 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 47823 T215 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 47824 T215 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 47825 T215 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 47826 T215 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 47827 T215 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 47829 T215 oass.SolrIndexSearcher.<init> Opening Searcher@40fa7565 main
[junit4:junit4] 2> 47829 T215 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3/tlog
[junit4:junit4] 2> 47830 T215 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 47830 T215 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 47838 T216 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@40fa7565 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 47842 T215 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 47843 T215 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 48877 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 48878 T163 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:46223/_agk",
[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:46223__agk",
[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> 48878 T163 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 48879 T163 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 48883 T214 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> 48883 T162 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> 48883 T198 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> 48883 T169 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> 48883 T182 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> 49858 T215 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 49859 T215 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:46223/_agk collection:collection1 shard:shard1
[junit4:junit4] 2> 49864 T215 oasc.ZkController.register We are http://127.0.0.1:46223/_agk/collection1/ and leader is http://127.0.0.1:44201/_agk/collection1/
[junit4:junit4] 2> 49865 T215 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:46223/_agk
[junit4:junit4] 2> 49865 T215 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 49866 T215 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C43 name=collection1 org.apache.solr.core.SolrCore@2406480c url=http://127.0.0.1:46223/_agk/collection1 node=127.0.0.1:46223__agk C43_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:46223/_agk, state=down, node_name=127.0.0.1:46223__agk, collection=collection1, core=collection1}
[junit4:junit4] 2> 49870 T217 C43 P46223 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 49870 T215 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 49871 T217 C43 P46223 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 49872 T217 C43 P46223 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 49873 T217 C43 P46223 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 49874 T140 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 49875 T140 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 49875 T217 C43 P46223 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 49877 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 49980 T178 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 49983 T140 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 49985 T140 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49900
[junit4:junit4] 2> 49986 T140 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 49987 T140 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 49987 T140 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1369314691650
[junit4:junit4] 2> 49988 T140 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1369314691650/solr.xml
[junit4:junit4] 2> 49988 T140 oasc.CoreContainer.<init> New CoreContainer 1292198998
[junit4:junit4] 2> 49989 T140 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1369314691650/'
[junit4:junit4] 2> 49990 T140 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1369314691650/'
[junit4:junit4] 2> 50036 T140 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 50037 T140 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 50038 T140 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 50038 T140 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 50039 T140 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 50040 T140 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 50040 T140 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 50041 T140 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 50042 T140 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 50042 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 50048 T140 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 50049 T140 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58582/solr
[junit4:junit4] 2> 50049 T140 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 50051 T140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 50052 T229 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@643ea832 name:ZooKeeperConnection Watcher:127.0.0.1:58582 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 50053 T140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 50054 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 50061 T140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 50062 T231 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@74b8f499 name:ZooKeeperConnection Watcher:127.0.0.1:58582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 50063 T140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 50066 T140 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 50390 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 50393 T163 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:46223/_agk",
[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:46223__agk",
[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> 50401 T162 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> 50402 T182 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> 50402 T214 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> 50402 T169 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> 50402 T231 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> 50401 T198 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> 50981 T178 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 50982 T178 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:46223__agk&core=collection1} status=0 QTime=1003
[junit4:junit4] 2> 51069 T140 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49900__agk
[junit4:junit4] 2> 51072 T140 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49900__agk
[junit4:junit4] 2> 51076 T169 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> 51077 T162 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 51077 T231 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 51077 T214 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 51076 T198 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> 51078 T231 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> 51078 T162 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> 51079 T214 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> 51081 T169 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 51078 T182 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 51083 T182 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> 51085 T198 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 51090 T232 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1369314691650/collection1
[junit4:junit4] 2> 51090 T232 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 51092 T232 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 51092 T232 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 51094 T232 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1369314691650/collection1/'
[junit4:junit4] 2> 51096 T232 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1369314691650/collection1/lib/README' to classloader
[junit4:junit4] 2> 51097 T232 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1369314691650/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 51124 T232 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 51167 T232 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 51169 T232 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 51175 T232 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 51559 T232 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 51568 T232 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 51571 T232 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 51587 T232 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 51592 T232 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 51597 T232 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 51598 T232 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 51598 T232 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 51599 T232 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 51600 T232 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 51600 T232 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 51600 T232 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 51601 T232 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1369314691650/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4/
[junit4:junit4] 2> 51601 T232 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2322e1d0
[junit4:junit4] 2> 51602 T232 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 51603 T232 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4
[junit4:junit4] 2> 51603 T232 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4/index/
[junit4:junit4] 2> 51604 T232 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 51604 T232 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4/index
[junit4:junit4] 2> 51606 T232 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8add7277 lockFactory=org.apache.lucene.store.NativeFSLockFactory@24abb17e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 51607 T232 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 51610 T232 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 51610 T232 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 51611 T232 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 51612 T232 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 51613 T232 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 51614 T232 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 51614 T232 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 51615 T232 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 51617 T232 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 51618 T232 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 51621 T232 oass.SolrIndexSearcher.<init> Opening Searcher@f6033fab main
[junit4:junit4] 2> 51621 T232 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4/tlog
[junit4:junit4] 2> 51622 T232 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 51622 T232 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 51632 T233 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f6033fab main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 51635 T232 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 51636 T232 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 51908 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 51910 T163 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:49900/_agk",
[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:49900__agk",
[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> 51910 T163 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 51910 T163 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 51915 T198 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> 51915 T214 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> 51915 T162 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> 51915 T182 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> 51915 T169 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> 51915 T231 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> 52638 T232 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 52638 T232 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49900/_agk collection:collection1 shard:shard2
[junit4:junit4] 2> 52644 T232 oasc.ZkController.register We are http://127.0.0.1:49900/_agk/collection1/ and leader is http://127.0.0.1:42260/_agk/collection1/
[junit4:junit4] 2> 52645 T232 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49900/_agk
[junit4:junit4] 2> 52645 T232 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 52646 T232 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C44 name=collection1 org.apache.solr.core.SolrCore@51b1398b url=http://127.0.0.1:49900/_agk/collection1 node=127.0.0.1:49900__agk C44_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:49900/_agk, state=down, node_name=127.0.0.1:49900__agk, collection=collection1, core=collection1}
[junit4:junit4] 2> 52647 T234 C44 P49900 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 52647 T232 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 52648 T234 C44 P49900 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 52649 T234 C44 P49900 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 52649 T234 C44 P49900 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 52650 T140 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 52651 T140 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 52651 T234 C44 P49900 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 52652 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 52671 T140 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 52672 T194 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 52676 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 52693 T178 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1369314678614/onenodecollectioncore
[junit4:junit4] 2> 52695 T178 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4] 2> 52697 T178 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4] 2> 52697 T178 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 52699 T178 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 52700 T178 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4] 2> 52701 T178 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4] 2> 52702 T178 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1369314678614/onenodecollectioncore/'
[junit4:junit4] 2> 52730 T178 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 52764 T178 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 52765 T178 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 52771 T178 oass.IndexSchema.readSchema [onenodecollectioncore] Schema name=test
[junit4:junit4] 2> ASYNC NEW_CORE C45 name=collection1 org.apache.solr.core.SolrCore@2406480c url=http://127.0.0.1:46223/_agk/collection1 node=127.0.0.1:46223__agk C45_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:46223/_agk, state=recovering, node_name=127.0.0.1:46223__agk, collection=collection1, shard=shard1, core=collection1}
[junit4:junit4] 2> 53005 T217 C45 P46223 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:44201/_agk/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 53008 T217 C45 P46223 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 53013 T217 C45 P46223 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:46223/_agk START replicas=[http://127.0.0.1:44201/_agk/collection1/] nUpdates=100
[junit4:junit4] 2> 53015 T217 C45 P46223 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 53015 T217 C45 P46223 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 53015 T217 C45 P46223 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 53015 T217 C45 P46223 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 53016 T217 C45 P46223 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 53016 T217 C45 P46223 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:44201/_agk/collection1/. core=collection1
[junit4:junit4] 2> 53017 T217 C45 P46223 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C46 name=collection1 org.apache.solr.core.SolrCore@5285ef80 url=http://127.0.0.1:44201/_agk/collection1 node=127.0.0.1:44201__agk C46_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:44201/_agk, state=active, node_name=127.0.0.1:44201__agk, collection=collection1, shard=shard1, core=collection1, leader=true}
[junit4:junit4] 2> 53025 T175 C46 P44201 oasc.SolrCore.execute [collection1] webapp=/_agk path=/get params={getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 53030 T176 C46 P44201 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 53032 T176 C46 P44201 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4dce7692 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7051b403),segFN=segments_1,generation=1}
[junit4:junit4] 2> 53032 T176 C46 P44201 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 53033 T176 C46 P44201 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4dce7692 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7051b403),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4dce7692 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7051b403),segFN=segments_2,generation=2}
[junit4:junit4] 2> 53034 T176 C46 P44201 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 53034 T176 C46 P44201 oass.SolrIndexSearcher.<init> Opening Searcher@94ab25a9 realtime
[junit4:junit4] 2> 53035 T176 C46 P44201 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 53036 T176 C46 P44201 oasup.LogUpdateProcessor.finish [collection1] webapp=/_agk path=/update params={softCommit=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin&openSearcher=false} {commit=} 0 9
[junit4:junit4] 2> ASYNC NEW_CORE C47 name=collection1 org.apache.solr.core.SolrCore@2406480c url=http://127.0.0.1:46223/_agk/collection1 node=127.0.0.1:46223__agk C47_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:46223/_agk, state=recovering, node_name=127.0.0.1:46223__agk, collection=collection1, shard=shard1, core=collection1}
[junit4:junit4] 2> 53050 T217 C47 P46223 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 53051 T217 C47 P46223 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
[junit4:junit4] 2> 53056 T217 C47 P46223 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> ASYNC NEW_CORE C48 name=collection1 org.apache.solr.core.SolrCore@5285ef80 url=http://127.0.0.1:44201/_agk/collection1 node=127.0.0.1:44201__agk C48_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:44201/_agk, state=active, node_name=127.0.0.1:44201__agk, collection=collection1, shard=shard1, core=collection1, leader=true}
[junit4:junit4] 2> 53066 T175 C48 P44201 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 53066 T175 C48 P44201 oasc.SolrCore.execute [collection1] webapp=/_agk path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=8
[junit4:junit4] 2> 53068 T217 C47 P46223 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 53068 T217 C47 P46223 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 53069 T217 C47 P46223 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 53072 T176 C48 P44201 oasc.SolrCore.execute [collection1] webapp=/_agk path=/replication params={qt=/replication&version=2&generation=2&command=filelist&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 53073 T217 C47 P46223 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 53073 T217 C47 P46223 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3/index.20130523231134832
[junit4:junit4] 2> 53074 T217 C47 P46223 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@f9b5c053 lockFactory=org.apache.lucene.store.NativeFSLockFactory@99327780) fullCopy=false
[junit4:junit4] 2> 53078 T177 C48 P44201 oasc.SolrCore.execute [collection1] webapp=/_agk path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=segments_2&wt=filestream} status=0 QTime=1
[junit4:junit4] 2> 53081 T217 C47 P46223 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> ASYNC NEW_CORE C49 name=collection1 org.apache.solr.core.SolrCore@2406480c url=http://127.0.0.1:46223/_agk/collection1 node=127.0.0.1:46223__agk C49_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:46223/_agk, state=recovering, node_name=127.0.0.1:46223__agk, collection=collection1, shard=shard1, core=collection1}
[junit4:junit4] 2> 53131 T217 C49 P46223 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 53131 T217 C49 P46223 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 53135 T178 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 53142 T178 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 53145 T178 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 53157 T178 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 53162 T178 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 53166 T178 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 53167 T178 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 53167 T178 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 53168 T178 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 53169 T178 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 53169 T178 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 53170 T178 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 53171 T178 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1369314678614/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1369314675009/onenodecollection/
[junit4:junit4] 2> 53171 T178 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2322e1d0
[junit4:junit4] 2> 53172 T178 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 53173 T178 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1369314675009/onenodecollection
[junit4:junit4] 2> 53174 T178 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1369314675009/onenodecollection/index/
[junit4:junit4] 2> 53174 T178 oasc.SolrCore.initIndex WARN [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1369314675009/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 53174 T217 C49 P46223 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@bf8e473f lockFactory=org.apache.lucene.store.NativeFSLockFactory@387ba27a),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@bf8e473f lockFactory=org.apache.lucene.store.NativeFSLockFactory@387ba27a),segFN=segments_2,generation=2}
[junit4:junit4] 2> 53175 T178 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1369314675009/onenodecollection/index
[junit4:junit4] 2> 53175 T217 C49 P46223 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 53176 T217 C49 P46223 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 53176 T217 C49 P46223 oass.SolrIndexSearcher.<init> Opening Searcher@35ba2a9e main
[junit4:junit4] 2> 53177 T178 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a11e327b lockFactory=org.apache.lucene.store.NativeFSLockFactory@ffa555bc),segFN=segments_1,generation=1}
[junit4:junit4] 2> 53178 T178 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 53178 T216 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@35ba2a9e main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 53180 T217 C49 P46223 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3/index.20130523231134832 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3/index.20130523231134832;done=true>>]
[junit4:junit4] 2> 53180 T217 C49 P46223 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3/index.20130523231134832
[junit4:junit4] 2> 53180 T217 C49 P46223 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3/index.20130523231134832
[junit4:junit4] 2> 53181 T178 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 53181 T217 C49 P46223 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 53181 T178 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 53181 T217 C49 P46223 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 53182 T217 C49 P46223 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 53182 T217 C49 P46223 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 53182 T178 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 53185 T178 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 53186 T217 C49 P46223 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 53186 T178 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 53187 T178 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 53187 T178 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 53188 T178 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 53189 T178 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 53190 T178 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 53193 T178 oass.SolrIndexSearcher.<init> Opening Searcher@e4a50495 main
[junit4:junit4] 2> 53193 T178 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1369314675009/onenodecollection/tlog
[junit4:junit4] 2> 53194 T178 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 53195 T178 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 53200 T238 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@e4a50495 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 53203 T178 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 53423 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 53425 T163 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:49900/_agk",
[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:49900__agk",
[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> 53430 T163 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:46223/_agk",
[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:46223__agk",
[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> 53435 T163 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:44201/_agk",
[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:44201__agk",
[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> 53436 T163 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4] 2> 53436 T163 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 53443 T162 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> 53443 T169 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> 53443 T182 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> 53443 T198 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> 53443 T214 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> 53443 T231 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> 53674 T194 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 53675 T194 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:49900__agk&core=collection1} status=0 QTime=1003
[junit4:junit4] 2> 54205 T178 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4] 2> 54206 T178 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:44201/_agk collection:onenodecollection shard:shard1
[junit4:junit4] 2> 54208 T178 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4] 2> 54216 T178 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 54220 T178 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 54222 T178 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 54223 T178 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44201/_agk/onenodecollectioncore/
[junit4:junit4] 2> 54224 T178 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 54225 T178 oasc.SyncStrategy.syncToMe http://127.0.0.1:44201/_agk/onenodecollectioncore/ has no replicas
[junit4:junit4] 2> 54226 T178 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44201/_agk/onenodecollectioncore/
[junit4:junit4] 2> 54227 T178 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4] 2> 54957 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 54972 T162 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> 54972 T231 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> 54972 T198 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> 54973 T182 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> 54973 T214 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> 54972 T169 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> 54988 T178 oasc.ZkController.register We are http://127.0.0.1:44201/_agk/onenodecollectioncore/ and leader is http://127.0.0.1:44201/_agk/onenodecollectioncore/
[junit4:junit4] 2> 54989 T178 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:44201/_agk
[junit4:junit4] 2> 54990 T178 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 54991 T178 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4] 2> 54994 T178 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 54997 T178 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1369314675009/onenodecollection&action=CREATE&version=2&numShards=1&name=onenodecollectioncore&wt=javabin&roles=none&collection=onenodecollection} status=0 QTime=2310
[junit4:junit4] 2> 54999 T140 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4] 2> 55000 T140 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C50 name=collection1 org.apache.solr.core.SolrCore@51b1398b url=http://127.0.0.1:49900/_agk/collection1 node=127.0.0.1:49900__agk C50_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:49900/_agk, state=recovering, node_name=127.0.0.1:49900__agk, collection=collection1, shard=shard2, core=collection1}
[junit4:junit4] 2> 55677 T234 C50 P49900 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:42260/_agk/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 55678 T234 C50 P49900 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:49900/_agk START replicas=[http://127.0.0.1:42260/_agk/collection1/] nUpdates=100
[junit4:junit4] 2> 55679 T234 C50 P49900 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 55679 T234 C50 P49900 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 55680 T234 C50 P49900 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 55680 T234 C50 P49900 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 55681 T234 C50 P49900 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 55681 T234 C50 P49900 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:42260/_agk/collection1/. core=collection1
[junit4:junit4] 2> 55682 T234 C50 P49900 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C51 name=collection1 org.apache.solr.core.SolrCore@26769025 url=http://127.0.0.1:42260/_agk/collection1 node=127.0.0.1:42260__agk C51_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:42260/_agk, state=active, node_name=127.0.0.1:42260__agk, collection=collection1, shard=shard2, core=collection1, leader=true}
[junit4:junit4] 2> 55702 T191 C51 P42260 oasc.SolrCore.execute [collection1] webapp=/_agk path=/get params={getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=0
[junit4:junit4] 2> 55705 T192 C51 P42260 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 55709 T192 C51 P42260 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@97560f1e lockFactory=org.apache.lucene.store.NativeFSLockFactory@14ebc68a),segFN=segments_1,generation=1}
[junit4:junit4] 2> 55710 T192 C51 P42260 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 55712 T192 C51 P42260 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@97560f1e lockFactory=org.apache.lucene.store.NativeFSLockFactory@14ebc68a),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@97560f1e lockFactory=org.apache.lucene.store.NativeFSLockFactory@14ebc68a),segFN=segments_2,generation=2}
[junit4:junit4] 2> 55713 T192 C51 P42260 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 55714 T192 C51 P42260 oass.SolrIndexSearcher.<init> Opening Searcher@7dacaf4c realtime
[junit4:junit4] 2> 55715 T192 C51 P42260 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 55717 T192 C51 P42260 oasup.LogUpdateProcessor.finish [collection1] webapp=/_agk path=/update params={softCommit=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin&openSearcher=false} {commit=} 0 12
[junit4:junit4] 2> ASYNC NEW_CORE C52 name=collection1 org.apache.solr.core.SolrCore@51b1398b url=http://127.0.0.1:49900/_agk/collection1 node=127.0.0.1:49900__agk C52_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:49900/_agk, state=recovering, node_name=127.0.0.1:49900__agk, collection=collection1, shard=shard2, core=collection1}
[junit4:junit4] 2> 55719 T234 C52 P49900 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 55720 T234 C52 P49900 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 55723 T191 C51 P42260 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 55723 T191 C51 P42260 oasc.SolrCore.execute [collection1] webapp=/_agk path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 55724 T234 C52 P49900 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 55725 T234 C52 P49900 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 55725 T234 C52 P49900 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 55729 T192 C51 P42260 oasc.SolrCore.execute [collection1] webapp=/_agk path=/replication params={qt=/replication&version=2&generation=2&command=filelist&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 55730 T234 C52 P49900 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 55731 T234 C52 P49900 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4/index.20130523231137489
[junit4:junit4] 2> 55731 T234 C52 P49900 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@c1d28052 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6c1209e6) fullCopy=false
[junit4:junit4] 2> 55735 T194 C51 P42260 oasc.SolrCore.execute [collection1] webapp=/_agk path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=segments_2&wt=filestream} status=0 QTime=0
[junit4:junit4] 2> 55737 T234 C52 P49900 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 55739 T234 C52 P49900 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 55739 T234 C52 P49900 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 55741 T234 C52 P49900 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8add7277 lockFactory=org.apache.lucene.store.NativeFSLockFactory@24abb17e),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8add7277 lockFactory=org.apache.lucene.store.NativeFSLockFactory@24abb17e),segFN=segments_2,generation=2}
[junit4:junit4] 2> 55741 T234 C52 P49900 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 55742 T234 C52 P49900 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 55742 T234 C52 P49900 oass.SolrIndexSearcher.<init> Opening Searcher@dc560727 main
[junit4:junit4] 2> 55744 T233 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@dc560727 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 55745 T234 C52 P49900 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4/index.20130523231137489 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4/index.20130523231137489;done=true>>]
[junit4:junit4] 2> 55745 T234 C52 P49900 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4/index.20130523231137489
[junit4:junit4] 2> 55745 T234 C52 P49900 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4/index.20130523231137489
[junit4:junit4] 2> 55746 T234 C52 P49900 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 55746 T234 C52 P49900 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 55747 T234 C52 P49900 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 55747 T234 C52 P49900 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 55748 T234 C52 P49900 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 56002 T140 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 56483 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 56486 T163 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:44201/_agk",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:44201__agk_onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:44201__agk",
[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> 56491 T163 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:49900/_agk",
[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:49900__agk",
[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> 56495 T162 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> 56495 T198 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> 56495 T231 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> 56495 T182 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> 56495 T169 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> 56495 T214 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> 57005 T140 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 57008 T140 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4] 2> 57009 T140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 57028 T140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 57029 T242 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b6a91b63 name:ZooKeeperConnection Watcher:127.0.0.1:58582 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 57029 T140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 57063 T140 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 41824
[junit4:junit4] 2> 57063 T140 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=-2135521897
[junit4:junit4] 2> 58001 T163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 58003 T163 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:41824/_agk",
[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:41824__agk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 58008 T198 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> 58008 T162 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> 58008 T214 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> 58008 T231 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> 58008 T182 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> 59065 T140 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 59066 T140 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 59080 T140 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@85f0291b
[junit4:junit4] 2> 59087 T140 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> 59087 T140 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 59088 T140 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 59088 T140 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 59089 T140 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 59090 T140 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 59090 T140 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/control/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/control/data/index;done=false>>]
[junit4:junit4] 2> 59091 T140 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/control/data/index
[junit4:junit4] 2> 59091 T140 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/control/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/control/data;done=false>>]
[junit4:junit4] 2> 59092 T140 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/control/data
[junit4:junit4] 2> 59093 T163 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89739406541783043-127.0.0.1:41824__agk-n_0000000000) am no longer a leader.
[junit4:junit4] 2> 59109 T198 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> 59110 T214 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 59110 T231 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 59110 T214 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> 59111 T231 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> 59129 T182 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 59131 T198 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 59132 T140 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/_agk,null}
[junit4:junit4] 2> 59149 T182 oasc.Overseer.start Overseer (id=89739406541783046-127.0.0.1:44201__agk-n_0000000001) starting
[junit4:junit4] 2> 59184 T140 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 44201
[junit4:junit4] 2> 59185 T140 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=-176917460
[junit4:junit4] 2> 59231 T244 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 59232 T182 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 59232 T182 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> 59233 T243 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 59237 T243 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 59241 T243 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:41824/_agk",
[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:41824__agk",
[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> 59247 T243 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44201/_agk",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:44201__agk_onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:44201__agk",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"onenodecollectioncore"}
[junit4:junit4] 2> 59252 T243 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44201/_agk",
[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:44201__agk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 59260 T198 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> 59260 T214 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> 59260 T182 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> 59261 T231 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> 60410 T162 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 60410 T162 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> 60410 T162 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 61220 T140 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 61222 T140 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 61225 T140 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 61228 T140 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5285ef80
[junit4:junit4] 2> 61239 T140 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> 61240 T140 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 61241 T140 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 61242 T140 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 61244 T140 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 61245 T140 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 61247 T140 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty1 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty1;done=false>>]
[junit4:junit4] 2> 61248 T140 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty1
[junit4:junit4] 2> 61249 T140 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty1/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty1/index;done=false>>]
[junit4:junit4] 2> 61250 T140 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty1/index
[junit4:junit4] 2> 61251 T140 oasc.SolrCore.close [onenodecollectioncore] CLOSING SolrCore org.apache.solr.core.SolrCore@26fde510
[junit4:junit4] 2> 61266 T140 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> 61266 T140 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 61267 T140 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 61267 T140 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 61268 T140 oasc.SolrCore.closeSearcher [onenodecollectioncore] Closing main searcher on request.
[junit4:junit4] 2> 61268 T140 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 61269 T140 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1369314675009/onenodecollection [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1369314675009/onenodecollection;done=false>>]
[junit4:junit4] 2> 61269 T140 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1369314675009/onenodecollection
[junit4:junit4] 2> 61270 T140 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1369314675009/onenodecollection/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1369314675009/onenodecollection/index;done=false>>]
[junit4:junit4] 2> 61270 T140 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1369314675009/onenodecollection/index
[junit4:junit4] 2> 61271 T243 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89739406541783046-127.0.0.1:44201__agk-n_0000000001) am no longer a leader.
[junit4:junit4] 2> 61272 T198 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> 61273 T231 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 61273 T231 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> 61273 T214 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 61274 T198 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 61275 T214 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 61275 T214 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 61276 T214 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 61276 T198 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 61276 T214 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:46223/_agk/collection1/
[junit4:junit4] 2> 61277 T214 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:46223/_agk START replicas=[http://127.0.0.1:44201/_agk/collection1/] nUpdates=100
[junit4:junit4] 2> 61278 T214 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:46223/_agk DONE. We have no versions. sync failed.
[junit4:junit4] 2> 61278 T198 oasc.Overseer.start Overseer (id=89739406541783048-127.0.0.1:42260__agk-n_0000000002) starting
[junit4:junit4] 2> 61278 T214 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 61279 T214 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> 61279 T214 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:46223/_agk/collection1/
[junit4:junit4] 2> 61280 T214 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 61281 T247 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 61282 T246 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 61283 T214 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 61284 T246 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 61284 T214 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> 61285 T246 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:44201/_agk",
[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:44201__agk",
[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> 61287 T246 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:44201/_agk",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:44201__agk_onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:44201__agk",
[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> 61294 T140 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/_agk,null}
[junit4:junit4] 2> 61298 T198 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> 61298 T214 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> 61298 T231 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> 61346 T140 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 42260
[junit4:junit4] 2> 61346 T140 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=-870445779
[junit4:junit4] 2> 62348 T140 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 62350 T140 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 62353 T140 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@26769025
[junit4:junit4] 2> 62363 T140 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> 62363 T140 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 62364 T140 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 62364 T140 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 62366 T140 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 62366 T140 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 62367 T140 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty2 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty2;done=false>>]
[junit4:junit4] 2> 62368 T140 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty2
[junit4:junit4] 2> 62368 T140 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty2/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty2/index;done=false>>]
[junit4:junit4] 2> 62369 T140 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty2/index
[junit4:junit4] 2> 62370 T246 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89739406541783048-127.0.0.1:42260__agk-n_0000000002) am no longer a leader.
[junit4:junit4] 2> 62371 T198 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> 62371 T198 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 62371 T198 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 62371 T231 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 62371 T214 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 62372 T231 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> 62372 T214 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> 62375 T231 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 62375 T214 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 62376 T214 oasc.Overseer.start Overseer (id=89739406541783050-127.0.0.1:46223__agk-n_0000000003) starting
[junit4:junit4] 2> 62376 T231 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 62377 T231 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 62377 T231 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 62377 T231 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49900/_agk/collection1/
[junit4:junit4] 2> 62378 T231 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 62378 T231 oasc.SyncStrategy.syncToMe http://127.0.0.1:49900/_agk/collection1/ has no replicas
[junit4:junit4] 2> 62378 T231 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49900/_agk/collection1/
[junit4:junit4] 2> 62379 T231 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 62380 T249 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 62380 T248 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 62382 T248 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 62383 T248 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42260/_agk",
[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:42260__agk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 62385 T248 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:42260/_agk",
[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:42260__agk",
[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> 62391 T140 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/_agk,null}
[junit4:junit4] 2> 62393 T214 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> 62393 T231 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> 62445 T140 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 46223
[junit4:junit4] 2> 62446 T140 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=-1044714278
[junit4:junit4] 2> 62572 T182 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 62573 T182 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> 62573 T182 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 63448 T140 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 63450 T140 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 63453 T140 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@2406480c
[junit4:junit4] 2> 63464 T140 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> 63465 T140 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 63466 T140 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 63467 T140 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 63469 T140 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 63470 T140 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 63472 T140 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3;done=false>>]
[junit4:junit4] 2> 63473 T140 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3
[junit4:junit4] 2> 63474 T140 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3/index;done=false>>]
[junit4:junit4] 2> 63475 T140 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty3/index
[junit4:junit4] 2> 63477 T248 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89739406541783050-127.0.0.1:46223__agk-n_0000000003) am no longer a leader.
[junit4:junit4] 2> 63479 T231 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4:junit4] 2> 63479 T231 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> 63484 T231 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 63487 T231 oasc.Overseer.start Overseer (id=89739406541783052-127.0.0.1:49900__agk-n_0000000004) starting
[junit4:junit4] 2> 63493 T251 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 63494 T250 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 63497 T250 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 63499 T140 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/_agk,null}
[junit4:junit4] 2> 63499 T250 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:46223/_agk",
[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:46223__agk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 63502 T250 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:46223/_agk",
[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:46223__agk",
[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> 63506 T231 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> 63551 T140 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 49900
[junit4:junit4] 2> 63552 T140 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1292198998
[junit4:junit4] 2> 64556 T140 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 64557 T140 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 64560 T140 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@51b1398b
[junit4:junit4] 2> 64578 T140 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> 64579 T140 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 64580 T140 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 64581 T140 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 64582 T140 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 64582 T140 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 64583 T140 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4;done=false>>]
[junit4:junit4] 2> 64583 T140 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4
[junit4:junit4] 2> 64584 T140 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4/index;done=false>>]
[junit4:junit4] 2> 64584 T140 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1369314675009/jetty4/index
[junit4:junit4] 2> 64585 T250 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89739406541783052-127.0.0.1:49900__agk-n_0000000004) am no longer a leader.
[junit4:junit4] 2> 64607 T140 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/_agk,null}
[junit4:junit4] 2> 64662 T140 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 64663 T140 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:58582 58582
[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":"89739406541783043-127.0.0.1:41824__agk-n_0000000000"}
[junit4:junit4] 1> /solr/overseer_elect/election (5)
[junit4:junit4] 1> /solr/overseer_elect/election/89739406541783050-127.0.0.1:46223__agk-n_0000000003 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89739406541783048-127.0.0.1:42260__agk-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89739406541783043-127.0.0.1:41824__agk-n_0000000000 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89739406541783052-127.0.0.1:49900__agk-n_0000000004 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89739406541783046-127.0.0.1:44201__agk-n_0000000001 (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/89739406541783043-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:41824/_agk",
[junit4:junit4] 1> "node_name":"127.0.0.1:41824__agk",
[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/89739406541783050-4-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/89739406541783046-2-n_0000000000 (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/89739406541783052-5-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/89739406541783048-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:44201/_agk",
[junit4:junit4] 1> "node_name":"127.0.0.1:44201__agk",
[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:42260/_agk",
[junit4:junit4] 1> "node_name":"127.0.0.1:42260__agk",
[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/89739406541783046-127.0.0.1:44201__agk_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:44201/_agk",
[junit4:junit4] 1> "node_name":"127.0.0.1:44201__agk",
[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:46223__agk (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:42260__agk (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:41824__agk (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:49900__agk (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:44201__agk (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:41824/_agk",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:41824__agk",
[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:44201__agk_onenodecollectioncore":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:44201/_agk",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:44201__agk",
[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:44201/_agk",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:44201__agk",
[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:46223/_agk",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:46223__agk",
[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:42260/_agk",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:42260__agk",
[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:49900/_agk",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:49900__agk",
[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=1F1F07593A8E84EF -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_CR -Dtests.timezone=Pacific/Truk -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 31.5s J1 | BasicDistributedZk2Test.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:42260/_agk/onenodecollectioncore returned non ok status:404, message:Can not find: /_agk/onenodecollectioncore/update
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([1F1F07593A8E84EF:9EF989414DD1E4D3]: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> 64701 T140 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 31461 T139 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4:junit4] 2> 64778 T214 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 64778 T214 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> 64778 T214 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 65886 T231 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 65886 T231 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> 65887 T231 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=DefaultSimilarity, locale=es_CR, timezone=Pacific/Truk
[junit4:junit4] 2> NOTE: Linux 3.2.0-41-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=2,free=13522344,total=46333952
[junit4:junit4] 2> NOTE: All tests run in this JVM: [SuggesterTSTTest, ZkNodePropsTest, TestSuggestSpellingConverter, TestZkChroot, TestSystemIdResolver, DocumentAnalysisRequestHandlerTest, TestCodecSupport, TestWordDelimiterFilterFactory, TestPartialUpdateDeduplication, IndexBasedSpellCheckerTest, OpenExchangeRatesOrgProviderTest, TestFieldResource, DebugComponentTest, TestElisionMultitermQuery, SuggesterWFSTTest, TestFoldingMultitermQuery, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 32.74s, 1 test, 1 error <<< FAILURES!
[...truncated 847 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: 295 suites, 1231 tests, 1 error, 14 ignored (8 assumptions)
Total time: 42 minutes 18 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure