You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/06/29 21:07:35 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/ibm-j9-jdk7) - Build # 6294
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/6294/
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:51607/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:51607/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
at __randomizedtesting.SeedInfo.seed([EC33A6A3A1E78DFB:6DD528BBD6B8EDC7]: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:835)
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 9788 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4] 2> 648276 T1926 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 648280 T1926 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372532232058
[junit4:junit4] 2> 648281 T1926 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 648281 T1927 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 648381 T1926 oasc.ZkTestServer.run start zk server on port:42058
[junit4:junit4] 2> 648383 T1926 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 648485 T1933 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@56849e48 name:ZooKeeperConnection Watcher:127.0.0.1:42058 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 648486 T1926 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 648487 T1926 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 648491 T1926 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 648494 T1935 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@88fe9735 name:ZooKeeperConnection Watcher:127.0.0.1:42058/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 648494 T1926 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 648495 T1926 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 648498 T1926 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 648500 T1926 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 648502 T1926 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 648504 T1926 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 648505 T1926 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 648508 T1926 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 648508 T1926 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 648511 T1926 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 648512 T1926 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 648514 T1926 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 648514 T1926 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 648516 T1926 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 648517 T1926 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 648520 T1926 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 648520 T1926 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 648522 T1926 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 648523 T1926 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 648525 T1926 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 648526 T1926 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 648528 T1926 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 648528 T1926 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 648609 T1926 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 648612 T1926 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47204
[junit4:junit4] 2> 648612 T1926 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 648613 T1926 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 648614 T1926 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372532232309
[junit4:junit4] 2> 648615 T1926 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372532232309/solr.xml
[junit4:junit4] 2> 648615 T1926 oasc.CoreContainer.<init> New CoreContainer 1385028480
[junit4:junit4] 2> 648616 T1926 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372532232309/'
[junit4:junit4] 2> 648617 T1926 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372532232309/'
[junit4:junit4] 2> 648675 T1926 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 648676 T1926 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 648677 T1926 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 648678 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 648679 T1926 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 648680 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 648681 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 648682 T1926 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 648683 T1926 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 648684 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 648691 T1926 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 648692 T1926 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42058/solr
[junit4:junit4] 2> 648693 T1926 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 648695 T1926 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 648697 T1946 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32e186d9 name:ZooKeeperConnection Watcher:127.0.0.1:42058 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 648697 T1926 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 648699 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 648706 T1926 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 648707 T1948 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9545eaa6 name:ZooKeeperConnection Watcher:127.0.0.1:42058/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 648707 T1926 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 648709 T1926 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 648712 T1926 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 648715 T1926 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 648716 T1926 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47204_
[junit4:junit4] 2> 648718 T1926 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47204_
[junit4:junit4] 2> 648721 T1926 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 648725 T1926 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 648728 T1926 oasc.Overseer.start Overseer (id=89950272360415235-127.0.0.1:47204_-n_0000000000) starting
[junit4:junit4] 2> 648731 T1926 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 648734 T1950 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 648735 T1926 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 648737 T1926 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 648738 T1926 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 648741 T1949 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 648743 T1951 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 648744 T1951 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 650247 T1949 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 650248 T1949 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:47204",
[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:47204_",
[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> 650248 T1949 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 650249 T1949 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 650252 T1948 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> 650745 T1951 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372532232309/collection1
[junit4:junit4] 2> 650745 T1951 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 650746 T1951 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 650747 T1951 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 650748 T1951 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372532232309/collection1/'
[junit4:junit4] 2> 650749 T1951 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372532232309/collection1/lib/README' to classloader
[junit4:junit4] 2> 650750 T1951 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372532232309/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 650779 T1951 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 650808 T1951 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 650809 T1951 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 650815 T1951 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 651125 T1951 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 651126 T1951 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 651126 T1951 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 651131 T1951 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 651134 T1951 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 651142 T1951 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 651145 T1951 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 651149 T1951 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 651149 T1951 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 651150 T1951 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 651150 T1951 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 651151 T1951 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 651151 T1951 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 651151 T1951 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 651152 T1951 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372532232309/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/control/data/
[junit4:junit4] 2> 651152 T1951 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@529e073c
[junit4:junit4] 2> 651153 T1951 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 651153 T1951 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/control/data
[junit4:junit4] 2> 651154 T1951 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/control/data/index/
[junit4:junit4] 2> 651154 T1951 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 651154 T1951 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/control/data/index
[junit4:junit4] 2> 651156 T1951 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b142a5a2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6a9d9fd0),segFN=segments_1,generation=1}
[junit4:junit4] 2> 651156 T1951 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 651157 T1951 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 651158 T1951 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 651158 T1951 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 651159 T1951 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 651159 T1951 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 651160 T1951 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 651160 T1951 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 651160 T1951 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 651161 T1951 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 651162 T1951 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 651164 T1951 oass.SolrIndexSearcher.<init> Opening Searcher@3448903f main
[junit4:junit4] 2> 651164 T1951 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/control/data/tlog
[junit4:junit4] 2> 651165 T1951 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 651165 T1951 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 651168 T1952 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3448903f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 651169 T1951 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 651170 T1951 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:47204 collection:control_collection shard:shard1
[junit4:junit4] 2> 651170 T1951 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 651174 T1951 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 651175 T1951 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 651176 T1951 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 651176 T1951 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:47204/collection1/
[junit4:junit4] 2> 651176 T1951 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 651177 T1951 oasc.SyncStrategy.syncToMe http://127.0.0.1:47204/collection1/ has no replicas
[junit4:junit4] 2> 651177 T1951 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:47204/collection1/
[junit4:junit4] 2> 651177 T1951 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 651755 T1949 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 651762 T1948 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> 651782 T1951 oasc.ZkController.register We are http://127.0.0.1:47204/collection1/ and leader is http://127.0.0.1:47204/collection1/
[junit4:junit4] 2> 651783 T1951 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47204
[junit4:junit4] 2> 651783 T1951 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 651783 T1951 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 651784 T1951 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 651785 T1951 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 651786 T1926 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 651787 T1926 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 651788 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 651793 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 651795 T1926 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 651797 T1955 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61a48b49 name:ZooKeeperConnection Watcher:127.0.0.1:42058/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 651797 T1926 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 651798 T1926 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 651801 T1926 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 651872 T1926 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 651874 T1926 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55596
[junit4:junit4] 2> 651875 T1926 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 651875 T1926 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 651876 T1926 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372532235579
[junit4:junit4] 2> 651876 T1926 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372532235579/solr.xml
[junit4:junit4] 2> 651877 T1926 oasc.CoreContainer.<init> New CoreContainer 734628551
[junit4:junit4] 2> 651878 T1926 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372532235579/'
[junit4:junit4] 2> 651878 T1926 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372532235579/'
[junit4:junit4] 2> 651916 T1926 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 651917 T1926 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 651918 T1926 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 651918 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 651919 T1926 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 651919 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 651920 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 651920 T1926 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 651921 T1926 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 651922 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 651926 T1926 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 651927 T1926 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42058/solr
[junit4:junit4] 2> 651927 T1926 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 651928 T1926 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 651930 T1966 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8f6645e1 name:ZooKeeperConnection Watcher:127.0.0.1:42058 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 651930 T1926 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 651931 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 651936 T1926 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 651937 T1968 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e32de3ba name:ZooKeeperConnection Watcher:127.0.0.1:42058/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 651937 T1926 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 651940 T1926 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 652942 T1926 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55596_
[junit4:junit4] 2> 652944 T1926 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55596_
[junit4:junit4] 2> 652947 T1948 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> 652947 T1968 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 652947 T1955 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 652949 T1948 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 652953 T1969 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 652954 T1969 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 653268 T1949 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 653269 T1949 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:47204",
[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:47204_",
[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> 653271 T1949 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:55596",
[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:55596_",
[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> 653272 T1949 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 653272 T1949 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 653274 T1968 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> 653274 T1955 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> 653274 T1948 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> 653955 T1969 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372532235579/collection1
[junit4:junit4] 2> 653956 T1969 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 653958 T1969 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 653958 T1969 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 653961 T1969 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372532235579/collection1/'
[junit4:junit4] 2> 653962 T1969 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372532235579/collection1/lib/README' to classloader
[junit4:junit4] 2> 653963 T1969 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372532235579/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 653998 T1969 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 654033 T1969 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 654034 T1969 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 654039 T1969 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 654363 T1969 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 654363 T1969 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 654364 T1969 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 654369 T1969 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 654371 T1969 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 654382 T1969 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 654385 T1969 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 654389 T1969 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 654390 T1969 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 654390 T1969 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 654390 T1969 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 654391 T1969 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 654392 T1969 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 654392 T1969 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 654392 T1969 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372532235579/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty1/
[junit4:junit4] 2> 654393 T1969 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@529e073c
[junit4:junit4] 2> 654393 T1969 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 654394 T1969 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty1
[junit4:junit4] 2> 654394 T1969 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty1/index/
[junit4:junit4] 2> 654395 T1969 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 654395 T1969 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty1/index
[junit4:junit4] 2> 654396 T1969 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ab49cb02 lockFactory=org.apache.lucene.store.NativeFSLockFactory@26352fc0),segFN=segments_1,generation=1}
[junit4:junit4] 2> 654397 T1969 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 654398 T1969 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 654399 T1969 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 654399 T1969 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 654400 T1969 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 654400 T1969 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 654401 T1969 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 654401 T1969 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 654401 T1969 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 654402 T1969 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 654403 T1969 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 654405 T1969 oass.SolrIndexSearcher.<init> Opening Searcher@92bfb9b9 main
[junit4:junit4] 2> 654405 T1969 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty1/tlog
[junit4:junit4] 2> 654406 T1969 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 654406 T1969 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 654410 T1970 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@92bfb9b9 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 654412 T1969 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 654413 T1969 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55596 collection:collection1 shard:shard1
[junit4:junit4] 2> 654414 T1969 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 654419 T1969 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 654421 T1969 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 654422 T1969 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 654422 T1969 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55596/collection1/
[junit4:junit4] 2> 654422 T1969 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 654423 T1969 oasc.SyncStrategy.syncToMe http://127.0.0.1:55596/collection1/ has no replicas
[junit4:junit4] 2> 654423 T1969 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55596/collection1/
[junit4:junit4] 2> 654423 T1969 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 654778 T1949 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 654783 T1968 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> 654784 T1955 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> 654784 T1948 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> 654829 T1969 oasc.ZkController.register We are http://127.0.0.1:55596/collection1/ and leader is http://127.0.0.1:55596/collection1/
[junit4:junit4] 2> 654830 T1969 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55596
[junit4:junit4] 2> 654831 T1969 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 654831 T1969 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 654832 T1969 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 654834 T1969 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 654836 T1926 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 654837 T1926 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 654838 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 654912 T1926 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 654914 T1926 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51607
[junit4:junit4] 2> 654915 T1926 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 654916 T1926 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 654916 T1926 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372532238623
[junit4:junit4] 2> 654917 T1926 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372532238623/solr.xml
[junit4:junit4] 2> 654918 T1926 oasc.CoreContainer.<init> New CoreContainer 253722751
[junit4:junit4] 2> 654918 T1926 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372532238623/'
[junit4:junit4] 2> 654919 T1926 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372532238623/'
[junit4:junit4] 2> 654957 T1926 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 654958 T1926 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 654959 T1926 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 654959 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 654960 T1926 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 654960 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 654961 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 654961 T1926 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 654962 T1926 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 654963 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 654967 T1926 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 654968 T1926 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42058/solr
[junit4:junit4] 2> 654969 T1926 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 654970 T1926 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 654971 T1982 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c4e4ff9b name:ZooKeeperConnection Watcher:127.0.0.1:42058 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 654971 T1926 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 654973 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 654977 T1926 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 654978 T1984 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a0f4b20c name:ZooKeeperConnection Watcher:127.0.0.1:42058/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 654979 T1926 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 654981 T1926 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 655984 T1926 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51607_
[junit4:junit4] 2> 655985 T1926 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51607_
[junit4:junit4] 2> 655987 T1955 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> 655987 T1948 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> 655987 T1984 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 655988 T1968 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 655988 T1955 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 655988 T1968 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> 655989 T1948 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 655991 T1985 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 655992 T1985 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 656288 T1949 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 656289 T1949 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:55596",
[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:55596_",
[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> 656291 T1949 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:51607",
[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:51607_",
[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> 656292 T1949 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 656292 T1949 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 656294 T1984 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> 656294 T1955 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> 656294 T1948 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> 656294 T1968 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> 656993 T1985 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372532238623/collection1
[junit4:junit4] 2> 656994 T1985 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 656995 T1985 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 656996 T1985 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 656997 T1985 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372532238623/collection1/'
[junit4:junit4] 2> 656999 T1985 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372532238623/collection1/lib/README' to classloader
[junit4:junit4] 2> 657000 T1985 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372532238623/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 657038 T1985 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 657079 T1985 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 657080 T1985 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 657084 T1985 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 657401 T1985 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 657402 T1985 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 657402 T1985 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 657407 T1985 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 657410 T1985 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 657423 T1985 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 657427 T1985 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 657430 T1985 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 657431 T1985 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 657431 T1985 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 657431 T1985 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 657432 T1985 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 657433 T1985 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 657433 T1985 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 657433 T1985 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372532238623/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty2/
[junit4:junit4] 2> 657434 T1985 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@529e073c
[junit4:junit4] 2> 657434 T1985 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 657435 T1985 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty2
[junit4:junit4] 2> 657435 T1985 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty2/index/
[junit4:junit4] 2> 657435 T1985 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 657436 T1985 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty2/index
[junit4:junit4] 2> 657437 T1985 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e98e2906 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5ddf1058),segFN=segments_1,generation=1}
[junit4:junit4] 2> 657438 T1985 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 657439 T1985 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 657439 T1985 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 657440 T1985 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 657440 T1985 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 657441 T1985 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 657441 T1985 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 657441 T1985 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 657442 T1985 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 657442 T1985 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 657444 T1985 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 657445 T1985 oass.SolrIndexSearcher.<init> Opening Searcher@41f691a1 main
[junit4:junit4] 2> 657446 T1985 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty2/tlog
[junit4:junit4] 2> 657446 T1985 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 657447 T1985 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 657450 T1986 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@41f691a1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 657452 T1985 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 657452 T1985 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51607 collection:collection1 shard:shard2
[junit4:junit4] 2> 657453 T1985 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 657457 T1985 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 657459 T1985 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 657460 T1985 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 657460 T1985 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51607/collection1/
[junit4:junit4] 2> 657460 T1985 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 657460 T1985 oasc.SyncStrategy.syncToMe http://127.0.0.1:51607/collection1/ has no replicas
[junit4:junit4] 2> 657461 T1985 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51607/collection1/
[junit4:junit4] 2> 657461 T1985 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 657799 T1949 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 657804 T1984 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> 657804 T1948 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> 657804 T1955 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> 657804 T1968 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> 657815 T1985 oasc.ZkController.register We are http://127.0.0.1:51607/collection1/ and leader is http://127.0.0.1:51607/collection1/
[junit4:junit4] 2> 657816 T1985 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51607
[junit4:junit4] 2> 657816 T1985 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 657816 T1985 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 657817 T1985 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 657819 T1985 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 657820 T1926 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 657821 T1926 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 657821 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 657890 T1926 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 657892 T1926 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44874
[junit4:junit4] 2> 657893 T1926 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 657893 T1926 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 657894 T1926 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372532241603
[junit4:junit4] 2> 657894 T1926 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372532241603/solr.xml
[junit4:junit4] 2> 657895 T1926 oasc.CoreContainer.<init> New CoreContainer 1245722728
[junit4:junit4] 2> 657895 T1926 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372532241603/'
[junit4:junit4] 2> 657896 T1926 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372532241603/'
[junit4:junit4] 2> 657933 T1926 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 657934 T1926 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 657934 T1926 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 657935 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 657935 T1926 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 657936 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 657937 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 657937 T1926 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 657938 T1926 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 657938 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 657942 T1926 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 657943 T1926 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42058/solr
[junit4:junit4] 2> 657944 T1926 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 657945 T1926 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 657946 T1998 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@afb0d597 name:ZooKeeperConnection Watcher:127.0.0.1:42058 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 657946 T1926 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 657948 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 657954 T1926 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 657955 T2000 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10df2825 name:ZooKeeperConnection Watcher:127.0.0.1:42058/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 657955 T1926 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 657958 T1926 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 658960 T1926 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44874_
[junit4:junit4] 2> 658962 T1926 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44874_
[junit4:junit4] 2> 658964 T1984 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> 658964 T2000 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 658964 T1955 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> 658964 T1968 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 658965 T1968 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> 658965 T1984 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 658964 T1948 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> 658966 T1955 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 658967 T1948 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 658972 T2001 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 658972 T2001 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 659309 T1949 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 659310 T1949 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:51607",
[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:51607_",
[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> 659313 T1949 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:44874",
[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:44874_",
[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> 659313 T1949 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 659314 T1949 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 659318 T2000 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> 659318 T1968 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> 659318 T1948 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> 659318 T1984 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> 659318 T1955 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> 659974 T2001 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372532241603/collection1
[junit4:junit4] 2> 659975 T2001 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 659976 T2001 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 659976 T2001 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 659977 T2001 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372532241603/collection1/'
[junit4:junit4] 2> 659978 T2001 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372532241603/collection1/lib/README' to classloader
[junit4:junit4] 2> 659978 T2001 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372532241603/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 660002 T2001 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 660034 T2001 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 660035 T2001 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 660039 T2001 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 660357 T2001 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 660358 T2001 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 660358 T2001 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 660363 T2001 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 660366 T2001 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 660374 T2001 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 660378 T2001 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 660381 T2001 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 660382 T2001 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 660383 T2001 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 660383 T2001 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 660384 T2001 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 660384 T2001 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 660385 T2001 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 660385 T2001 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372532241603/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty3/
[junit4:junit4] 2> 660386 T2001 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@529e073c
[junit4:junit4] 2> 660386 T2001 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 660387 T2001 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty3
[junit4:junit4] 2> 660387 T2001 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty3/index/
[junit4:junit4] 2> 660388 T2001 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 660388 T2001 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty3/index
[junit4:junit4] 2> 660390 T2001 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7df3266 lockFactory=org.apache.lucene.store.NativeFSLockFactory@b377e64),segFN=segments_1,generation=1}
[junit4:junit4] 2> 660390 T2001 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 660392 T2001 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 660392 T2001 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 660393 T2001 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 660394 T2001 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 660395 T2001 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 660395 T2001 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 660396 T2001 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 660397 T2001 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 660397 T2001 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 660399 T2001 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 660402 T2001 oass.SolrIndexSearcher.<init> Opening Searcher@23e045c6 main
[junit4:junit4] 2> 660403 T2001 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty3/tlog
[junit4:junit4] 2> 660404 T2001 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 660404 T2001 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 660408 T2002 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@23e045c6 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 660409 T2001 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 660409 T2001 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44874 collection:collection1 shard:shard1
[junit4:junit4] 2> 660412 T2001 oasc.ZkController.register We are http://127.0.0.1:44874/collection1/ and leader is http://127.0.0.1:55596/collection1/
[junit4:junit4] 2> 660412 T2001 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44874
[junit4:junit4] 2> 660413 T2001 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 660413 T2001 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C1687 name=collection1 org.apache.solr.core.SolrCore@730a52c2 url=http://127.0.0.1:44874/collection1 node=127.0.0.1:44874_ C1687_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:44874, state=down, node_name=127.0.0.1:44874_, collection=collection1, core=collection1}
[junit4:junit4] 2> 660413 T2003 C1687 P44874 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 660414 T2003 C1687 P44874 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 660414 T2001 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 660414 T2003 C1687 P44874 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 660414 T2003 C1687 P44874 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 660415 T1926 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 660415 T1926 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 660415 T2003 C1687 P44874 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 660416 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 660421 T1962 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 660488 T1926 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 660490 T1926 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:38124
[junit4:junit4] 2> 660490 T1926 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 660491 T1926 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 660492 T1926 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372532244199
[junit4:junit4] 2> 660492 T1926 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372532244199/solr.xml
[junit4:junit4] 2> 660493 T1926 oasc.CoreContainer.<init> New CoreContainer 1244356598
[junit4:junit4] 2> 660493 T1926 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372532244199/'
[junit4:junit4] 2> 660494 T1926 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372532244199/'
[junit4:junit4] 2> 660533 T1926 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 660534 T1926 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 660534 T1926 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 660535 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 660535 T1926 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 660536 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 660536 T1926 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 660537 T1926 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 660538 T1926 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 660538 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 660543 T1926 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 660543 T1926 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42058/solr
[junit4:junit4] 2> 660544 T1926 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 660545 T1926 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 660546 T2015 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d92f2c41 name:ZooKeeperConnection Watcher:127.0.0.1:42058 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 660546 T1926 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 660548 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 660552 T1926 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 660553 T2017 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77cb8c0a name:ZooKeeperConnection Watcher:127.0.0.1:42058/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 660553 T1926 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 660556 T1926 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 660825 T1949 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 660826 T1949 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:44874",
[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:44874_",
[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> 660831 T1968 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> 660831 T2000 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> 660831 T1948 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> 660831 T2017 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> 660831 T1955 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> 660831 T1984 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> 661422 T1962 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 661423 T1962 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:44874_&core=collection1} status=0 QTime=1002
[junit4:junit4] 2> 661559 T1926 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38124_
[junit4:junit4] 2> 661560 T1926 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38124_
[junit4:junit4] 2> 661562 T1984 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> 661562 T1948 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> 661562 T1955 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> 661563 T2000 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 661562 T1968 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 661564 T2000 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> 661564 T1984 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 661563 T2017 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 661564 T1955 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 661564 T1948 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 661565 T2017 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> 661564 T1968 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> 661568 T2018 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 661568 T2018 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 662335 T1949 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 662335 T1949 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:38124",
[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:38124_",
[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> 662336 T1949 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 662336 T1949 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 662339 T1955 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> 662339 T1968 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> 662339 T1948 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> 662339 T2000 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> 662339 T2017 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> 662339 T1984 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> 662569 T2018 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372532244199/collection1
[junit4:junit4] 2> 662570 T2018 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 662570 T2018 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 662571 T2018 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 662572 T2018 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372532244199/collection1/'
[junit4:junit4] 2> 662572 T2018 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372532244199/collection1/lib/README' to classloader
[junit4:junit4] 2> 662573 T2018 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372532244199/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 662597 T2018 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 662632 T2018 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 662633 T2018 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 662638 T2018 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 662981 T2018 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 662982 T2018 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 662982 T2018 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 662987 T2018 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 662990 T2018 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 662998 T2018 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 663001 T2018 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 663005 T2018 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 663005 T2018 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 663006 T2018 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 663006 T2018 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 663007 T2018 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 663007 T2018 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 663008 T2018 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 663008 T2018 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372532244199/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty4/
[junit4:junit4] 2> 663008 T2018 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@529e073c
[junit4:junit4] 2> 663009 T2018 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 663009 T2018 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty4
[junit4:junit4] 2> 663010 T2018 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty4/index/
[junit4:junit4] 2> 663010 T2018 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 663011 T2018 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty4/index
[junit4:junit4] 2> 663012 T2018 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@efa88502 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e8d8f5be),segFN=segments_1,generation=1}
[junit4:junit4] 2> 663012 T2018 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 663014 T2018 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 663014 T2018 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 663015 T2018 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 663015 T2018 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 663016 T2018 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 663016 T2018 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 663017 T2018 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 663017 T2018 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 663017 T2018 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 663019 T2018 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 663021 T2018 oass.SolrIndexSearcher.<init> Opening Searcher@d6f66550 main
[junit4:junit4] 2> 663021 T2018 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty4/tlog
[junit4:junit4] 2> 663022 T2018 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 663022 T2018 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 663026 T2019 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d6f66550 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 663028 T2018 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 663028 T2018 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:38124 collection:collection1 shard:shard2
[junit4:junit4] 2> 663030 T2018 oasc.ZkController.register We are http://127.0.0.1:38124/collection1/ and leader is http://127.0.0.1:51607/collection1/
[junit4:junit4] 2> 663030 T2018 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38124
[junit4:junit4] 2> 663031 T2018 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 663031 T2018 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C1688 name=collection1 org.apache.solr.core.SolrCore@cee3e326 url=http://127.0.0.1:38124/collection1 node=127.0.0.1:38124_ C1688_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:38124, state=down, node_name=127.0.0.1:38124_, collection=collection1, core=collection1}
[junit4:junit4] 2> 663031 T2020 C1688 P38124 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 663032 T2018 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 663032 T2020 C1688 P38124 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 663032 T2020 C1688 P38124 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 663033 T2020 C1688 P38124 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 663033 T1926 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 663033 T1926 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 663033 T2020 C1688 P38124 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 663034 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 663041 T1926 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 663041 T1979 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 663043 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 663052 T1963 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> ASYNC NEW_CORE C1689 name=collection1 org.apache.solr.core.SolrCore@730a52c2 url=http://127.0.0.1:44874/collection1 node=127.0.0.1:44874_ C1689_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:44874, state=recovering, node_name=127.0.0.1:44874_, collection=collection1, shard=shard1, core=collection1}
[junit4:junit4] 2> 663424 T2003 C1689 P44874 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:55596/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 663425 T2003 C1689 P44874 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:44874 START replicas=[http://127.0.0.1:55596/collection1/] nUpdates=100
[junit4:junit4] 2> 663425 T2003 C1689 P44874 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 663426 T2003 C1689 P44874 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 663426 T2003 C1689 P44874 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 663426 T2003 C1689 P44874 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 663426 T2003 C1689 P44874 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 663427 T2003 C1689 P44874 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:55596/collection1/. core=collection1
[junit4:junit4] 2> 663427 T2003 C1689 P44874 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C1690 name=collection1 org.apache.solr.core.SolrCore@53e6b3ae url=http://127.0.0.1:55596/collection1 node=127.0.0.1:55596_ C1690_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:55596, state=active, node_name=127.0.0.1:55596_, collection=collection1, shard=shard1, core=collection1, leader=true}
[junit4:junit4] 2> 663429 T1962 C1690 P55596 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=0
[junit4:junit4] 2> 663434 T1964 C1690 P55596 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 663435 T1964 C1690 P55596 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ab49cb02 lockFactory=org.apache.lucene.store.NativeFSLockFactory@26352fc0),segFN=segments_1,generation=1}
[junit4:junit4] 2> 663436 T1964 C1690 P55596 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 663437 T1964 C1690 P55596 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 663438 T1964 C1690 P55596 oass.SolrIndexSearcher.<init> Opening Searcher@cff55741 realtime
[junit4:junit4] 2> 663438 T1964 C1690 P55596 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 663439 T1964 C1690 P55596 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={softCommit=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin&openSearcher=false} {commit=} 0 5
[junit4:junit4] 2> 663440 T2003 C1689 P44874 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 663440 T2003 C1689 P44874 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 663442 T1961 C1690 P55596 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 663443 T1961 C1690 P55596 oasc.SolrCore.execute [collection1] webapp= path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=2
[junit4:junit4] 2> 663443 T2003 C1689 P44874 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 663444 T2003 C1689 P44874 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 663444 T2003 C1689 P44874 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 663444 T2003 C1689 P44874 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 663445 T2003 C1689 P44874 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 663842 T1949 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 663843 T1949 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:38124",
[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:38124_",
[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> 663845 T1949 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:55596",
[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:55596_",
[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> 663845 T1949 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4] 2> 663846 T1949 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 663848 T1949 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:44874",
[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:44874_",
[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> 663850 T1968 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> 663850 T2000 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> 663850 T1955 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> 663851 T2017 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> 663851 T1984 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> 663851 T1948 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> 664043 T1979 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 664044 T1979 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:38124_&core=collection1} status=0 QTime=1003
[junit4:junit4] 2> 664055 T1963 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372532235579/onenodecollectioncore
[junit4:junit4] 2> 664056 T1963 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4] 2> 664057 T1963 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4] 2> 664058 T1963 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 664059 T1963 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 664060 T1963 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4] 2> 664062 T1963 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4] 2> 664063 T1963 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372532235579/onenodecollectioncore/'
[junit4:junit4] 2> 664089 T1963 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 664120 T1963 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 664122 T1963 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 664126 T1963 oass.IndexSchema.readSchema [onenodecollectioncore] Schema name=test
[junit4:junit4] 2> 664464 T1963 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 664465 T1963 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 664466 T1963 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 664471 T1963 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 664474 T1963 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 664484 T1963 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 664488 T1963 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 664492 T1963 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 664493 T1963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 664494 T1963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 664495 T1963 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 664497 T1963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 664498 T1963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 664500 T1963 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 664501 T1963 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372532235579/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372532232058/onenodecollection/
[junit4:junit4] 2> 664502 T1963 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@529e073c
[junit4:junit4] 2> 664503 T1963 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 664504 T1963 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372532232058/onenodecollection
[junit4:junit4] 2> 664505 T1963 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372532232058/onenodecollection/index/
[junit4:junit4] 2> 664506 T1963 oasc.SolrCore.initIndex WARN [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372532232058/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 664507 T1963 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372532232058/onenodecollection/index
[junit4:junit4] 2> 664509 T1963 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f9ccd0c6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@522234bb),segFN=segments_1,generation=1}
[junit4:junit4] 2> 664509 T1963 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 664511 T1963 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 664512 T1963 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 664513 T1963 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 664514 T1963 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 664515 T1963 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 664515 T1963 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 664516 T1963 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 664517 T1963 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 664517 T1963 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 664519 T1963 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 664521 T1963 oass.SolrIndexSearcher.<init> Opening Searcher@eb10c891 main
[junit4:junit4] 2> 664522 T1963 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372532232058/onenodecollection/tlog
[junit4:junit4] 2> 664523 T1963 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 664524 T1963 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 664527 T2023 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@eb10c891 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 664529 T1963 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4] 2> 664529 T1963 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:55596 collection:onenodecollection shard:shard1
[junit4:junit4] 2> 664531 T1963 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4] 2> 664537 T1963 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 664539 T1963 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 664540 T1963 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 664540 T1963 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55596/onenodecollectioncore/
[junit4:junit4] 2> 664541 T1963 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 664541 T1963 oasc.SyncStrategy.syncToMe http://127.0.0.1:55596/onenodecollectioncore/ has no replicas
[junit4:junit4] 2> 664542 T1963 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55596/onenodecollectioncore/
[junit4:junit4] 2> 664543 T1963 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4] 2> 665355 T1949 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 665361 T1968 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> 665361 T2000 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> 665361 T2017 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> 665361 T1984 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> 665362 T1948 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> 665361 T1955 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> 665400 T1963 oasc.ZkController.register We are http://127.0.0.1:55596/onenodecollectioncore/ and leader is http://127.0.0.1:55596/onenodecollectioncore/
[junit4:junit4] 2> 665401 T1963 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:55596
[junit4:junit4] 2> 665401 T1963 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 665402 T1963 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4] 2> 665404 T1963 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 665405 T1963 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372532232058/onenodecollection&action=CREATE&version=2&numShards=1&name=onenodecollectioncore&wt=javabin&roles=none&collection=onenodecollection} status=0 QTime=2353
[junit4:junit4] 2> 665406 T1926 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4] 2> 665406 T1926 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C1691 name=collection1 org.apache.solr.core.SolrCore@cee3e326 url=http://127.0.0.1:38124/collection1 node=127.0.0.1:38124_ C1691_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:38124, state=recovering, node_name=127.0.0.1:38124_, collection=collection1, shard=shard2, core=collection1}
[junit4:junit4] 2> 666045 T2020 C1691 P38124 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:51607/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 666045 T2020 C1691 P38124 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:38124 START replicas=[http://127.0.0.1:51607/collection1/] nUpdates=100
[junit4:junit4] 2> 666046 T2020 C1691 P38124 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 666046 T2020 C1691 P38124 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 666046 T2020 C1691 P38124 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 666046 T2020 C1691 P38124 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 666047 T2020 C1691 P38124 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 666047 T2020 C1691 P38124 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:51607/collection1/. core=collection1
[junit4:junit4] 2> 666047 T2020 C1691 P38124 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C1692 name=collection1 org.apache.solr.core.SolrCore@54843041 url=http://127.0.0.1:51607/collection1 node=127.0.0.1:51607_ C1692_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:51607, state=active, node_name=127.0.0.1:51607_, collection=collection1, shard=shard2, core=collection1, leader=true}
[junit4:junit4] 2> 666053 T1979 C1692 P51607 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 666055 T1980 C1692 P51607 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 666057 T1980 C1692 P51607 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e98e2906 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5ddf1058),segFN=segments_1,generation=1}
[junit4:junit4] 2> 666059 T1980 C1692 P51607 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 666060 T1980 C1692 P51607 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 666061 T1980 C1692 P51607 oass.SolrIndexSearcher.<init> Opening Searcher@cf833763 realtime
[junit4:junit4] 2> 666062 T1980 C1692 P51607 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 666063 T1980 C1692 P51607 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={softCommit=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin&openSearcher=false} {commit=} 0 8
[junit4:junit4] 2> 666065 T2020 C1691 P38124 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 666065 T2020 C1691 P38124 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 666066 T1978 C1692 P51607 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 666067 T1978 C1692 P51607 oasc.SolrCore.execute [collection1] webapp= path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 666068 T2020 C1691 P38124 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 666068 T2020 C1691 P38124 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 666068 T2020 C1691 P38124 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 666068 T2020 C1691 P38124 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 666070 T2020 C1691 P38124 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 666408 T1926 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 666868 T1949 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 666869 T1949 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:55596",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:55596__onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:55596_",
[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> 666873 T1949 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:38124",
[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:38124_",
[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> 666877 T1968 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> 666877 T1948 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> 666877 T2000 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> 666877 T1955 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> 666877 T1984 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> 666877 T2017 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> 667410 T1926 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 667411 T1926 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4] 2> 667411 T1926 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 667420 T1926 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 667421 T2026 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1321094e name:ZooKeeperConnection Watcher:127.0.0.1:42058 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 667421 T1926 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 667457 T1926 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 47204
[junit4:junit4] 2> 667459 T1926 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1385028480
[junit4:junit4] 2> 668382 T1949 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 668382 T1949 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:47204",
[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:47204_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 668385 T1984 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> 668385 T2017 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> 668385 T1948 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> 668385 T2000 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> 668385 T1968 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> 669462 T1926 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 669463 T1926 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 669465 T1926 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@162400ad
[junit4:junit4] 2> 669469 T1926 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> 669470 T1926 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 669471 T1926 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 669471 T1926 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 669472 T1926 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 669473 T1926 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 669474 T1926 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/control/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/control/data/index;done=false>>]
[junit4:junit4] 2> 669475 T1926 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/control/data/index
[junit4:junit4] 2> 669476 T1926 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/control/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/control/data;done=false>>]
[junit4:junit4] 2> 669476 T1926 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/control/data
[junit4:junit4] 2> 669478 T1949 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89950272360415235-127.0.0.1:47204_-n_0000000000) am no longer a leader.
[junit4:junit4] 2> 669478 T1948 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> 669478 T1968 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 669479 T1948 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 669479 T2000 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 669479 T2017 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 669479 T1948 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 669479 T2000 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> 669479 T1968 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> 669478 T1984 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> 669480 T2017 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> 669483 T1984 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 669483 T1968 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 669484 T1968 oasc.Overseer.start Overseer (id=89950272360415238-127.0.0.1:55596_-n_0000000001) starting
[junit4:junit4] 2> 669488 T2028 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 669489 T2027 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 669491 T2027 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 669491 T2027 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:47204",
[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:47204_",
[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> 669496 T2000 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> 669496 T2017 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> 669496 T1984 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> 669496 T1968 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> 669499 T1926 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 669551 T1926 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 55596
[junit4:junit4] 2> 669552 T1926 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=734628551
[junit4:junit4] 2> 670999 T2027 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 671000 T2027 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55596",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:55596__onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:55596_",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"onenodecollectioncore"}
[junit4:junit4] 2> 671002 T2027 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55596",
[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:55596_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 671005 T1968 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> 671005 T2017 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> 671005 T2000 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> 671005 T1984 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> 672554 T1926 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 672555 T1926 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 672557 T1926 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 672559 T1926 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@53e6b3ae
[junit4:junit4] 2> 672564 T1926 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> 672565 T1926 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 672565 T1926 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 672566 T1926 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 672567 T1926 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 672567 T1926 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 672568 T1926 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty1/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty1/index;done=false>>]
[junit4:junit4] 2> 672568 T1926 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty1/index
[junit4:junit4] 2> 672569 T1926 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty1 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty1;done=false>>]
[junit4:junit4] 2> 672569 T1926 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty1
[junit4:junit4] 2> 672570 T1926 oasc.SolrCore.close [onenodecollectioncore] CLOSING SolrCore org.apache.solr.core.SolrCore@983270e1
[junit4:junit4] 2> 672574 T1926 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> 672575 T1926 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 672575 T1926 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 672576 T1926 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 672576 T1926 oasc.SolrCore.closeSearcher [onenodecollectioncore] Closing main searcher on request.
[junit4:junit4] 2> 672577 T1926 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 672577 T1926 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372532232058/onenodecollection [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372532232058/onenodecollection;done=false>>]
[junit4:junit4] 2> 672578 T1926 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372532232058/onenodecollection
[junit4:junit4] 2> 672579 T1926 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372532232058/onenodecollection/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372532232058/onenodecollection/index;done=false>>]
[junit4:junit4] 2> 672579 T1926 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372532232058/onenodecollection/index
[junit4:junit4] 2> 672580 T2027 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89950272360415238-127.0.0.1:55596_-n_0000000001) am no longer a leader.
[junit4:junit4] 2> 672581 T2017 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 672581 T2017 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> 672581 T2000 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 672581 T1984 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 672583 T2000 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 672583 T2000 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 672584 T2000 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 672584 T1984 oasc.Overseer.start Overseer (id=89950272360415240-127.0.0.1:51607_-n_0000000002) starting
[junit4:junit4] 2> 672584 T2000 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44874/collection1/
[junit4:junit4] 2> 672585 T2000 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:44874 START replicas=[http://127.0.0.1:55596/collection1/] nUpdates=100
[junit4:junit4] 2> 672585 T2000 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:44874 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 672585 T2000 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next candidate
[junit4:junit4] 2> 672586 T2000 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> 672586 T2000 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44874/collection1/
[junit4:junit4] 2> 672586 T2000 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 672587 T1984 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> 672587 T2031 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 672588 T2030 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 672588 T1984 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 672590 T2000 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 672590 T2030 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 672590 T2000 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> 672591 T2030 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:55596",
[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:55596_",
[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> 672593 T2030 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:55596",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:55596__onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:55596_",
[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> 672598 T1984 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> 672598 T2017 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> 672598 T2000 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> 672601 T1926 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 672653 T1926 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 51607
[junit4:junit4] 2> 672653 T1926 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=253722751
[junit4:junit4] 2> 673655 T1926 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 673656 T1926 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 673658 T1926 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@54843041
[junit4:junit4] 2> 673661 T1926 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> 673661 T1926 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 673662 T1926 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 673662 T1926 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 673663 T1926 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 673664 T1926 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 673664 T1926 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty2 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty2;done=false>>]
[junit4:junit4] 2> 673665 T1926 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty2
[junit4:junit4] 2> 673665 T1926 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty2/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty2/index;done=false>>]
[junit4:junit4] 2> 673666 T1926 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty2/index
[junit4:junit4] 2> 673667 T2030 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89950272360415240-127.0.0.1:51607_-n_0000000002) am no longer a leader.
[junit4:junit4] 2> 673668 T1984 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> 673668 T1984 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 673668 T1984 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 673669 T2017 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 673669 T2000 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 673670 T2017 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 673671 T2017 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 673671 T2017 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 673671 T2000 oasc.Overseer.start Overseer (id=89950272360415242-127.0.0.1:44874_-n_0000000003) starting
[junit4:junit4] 2> 673671 T2017 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:38124/collection1/
[junit4:junit4] 2> 673672 T2017 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:38124 START replicas=[http://127.0.0.1:51607/collection1/] nUpdates=100
[junit4:junit4] 2> 673672 T2017 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:38124 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 673673 T2017 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next candidate
[junit4:junit4] 2> 673673 T2017 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> 673673 T2017 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38124/collection1/
[junit4:junit4] 2> 673673 T2017 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 673675 T2034 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 673675 T2000 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 673675 T2000 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> 673676 T2033 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 673677 T2017 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 673678 T2017 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> 673678 T2033 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 673678 T1926 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 673679 T2033 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51607",
[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:51607_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 673681 T2033 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:51607",
[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:51607_",
[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> 673687 T2000 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> 673687 T2017 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> 673731 T1926 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 44874
[junit4:junit4] 2> 673732 T1926 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1245722728
[junit4:junit4] 2> 673881 T1968 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 673881 T1968 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> 673881 T1968 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 674733 T1926 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 674734 T1926 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 674735 T1926 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@730a52c2
[junit4:junit4] 2> 674738 T1926 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> 674739 T1926 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 674739 T1926 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 674740 T1926 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 674740 T1926 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 674741 T1926 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 674741 T1926 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty3 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty3;done=false>>]
[junit4:junit4] 2> 674742 T1926 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty3
[junit4:junit4] 2> 674742 T1926 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty3/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty3/index;done=false>>]
[junit4:junit4] 2> 674743 T1926 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty3/index
[junit4:junit4] 2> 674743 T2033 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89950272360415242-127.0.0.1:44874_-n_0000000003) am no longer a leader.
[junit4:junit4] 2> 674744 T2000 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 674744 T2000 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> 674745 T2000 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 674745 T2017 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 674747 T2017 oasc.Overseer.start Overseer (id=89950272360415244-127.0.0.1:38124_-n_0000000004) starting
[junit4:junit4] 2> 674750 T2017 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4:junit4] 2> 674750 T2036 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 674751 T2035 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 674750 T2017 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> 674752 T2035 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 674753 T2035 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44874",
[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:44874_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 674755 T2035 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:44874",
[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:44874_",
[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> 674759 T2017 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> 674765 T1926 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 674818 T1926 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 38124
[junit4:junit4] 2> 674818 T1926 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1244356598
[junit4:junit4] 2> 675821 T1926 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 675821 T1926 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 675823 T1926 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@cee3e326
[junit4:junit4] 2> 675828 T1926 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> 675829 T1926 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 675829 T1926 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 675830 T1926 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 675830 T1926 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 675831 T1926 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 675831 T1926 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty4;done=false>>]
[junit4:junit4] 2> 675832 T1926 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty4
[junit4:junit4] 2> 675832 T1926 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty4/index;done=false>>]
[junit4:junit4] 2> 675833 T1926 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372532232058/jetty4/index
[junit4:junit4] 2> 675834 T2035 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89950272360415244-127.0.0.1:38124_-n_0000000004) am no longer a leader.
[junit4:junit4] 2> 675855 T1926 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 675912 T1926 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 675913 T1926 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42058 42058
[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":"89950272360415235-127.0.0.1:47204_-n_0000000000"}
[junit4:junit4] 1> /solr/overseer_elect/election (5)
[junit4:junit4] 1> /solr/overseer_elect/election/89950272360415242-127.0.0.1:44874_-n_0000000003 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89950272360415240-127.0.0.1:51607_-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89950272360415238-127.0.0.1:55596_-n_0000000001 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89950272360415244-127.0.0.1:38124_-n_0000000004 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89950272360415235-127.0.0.1:47204_-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections (3)
[junit4:junit4] 1> /solr/collections/control_collection (3)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"configName":"conf1"}
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election/89950272360415235-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:47204",
[junit4:junit4] 1> "node_name":"127.0.0.1:47204_",
[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/89950272360415242-4-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/89950272360415238-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/89950272360415244-5-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/89950272360415240-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:55596",
[junit4:junit4] 1> "node_name":"127.0.0.1:55596_",
[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:51607",
[junit4:junit4] 1> "node_name":"127.0.0.1:51607_",
[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/89950272360415238-127.0.0.1:55596__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:55596",
[junit4:junit4] 1> "node_name":"127.0.0.1:55596_",
[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:47204_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:55596_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:51607_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:38124_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:44874_ (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:47204",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:47204_",
[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:55596__onenodecollectioncore":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:55596",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:55596_",
[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:55596",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:55596_",
[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:44874",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:44874_",
[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:51607",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:51607_",
[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:38124",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:38124_",
[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=EC33A6A3A1E78DFB -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=nl -Dtests.timezone=Africa/Blantyre -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 27.7s J1 | BasicDistributedZk2Test.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:51607/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([EC33A6A3A1E78DFB:6DD528BBD6B8EDC7]: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:835)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:780)
[junit4:junit4] 2> 675942 T1926 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 27671 T1925 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4] 2> 677134 T2017 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 677135 T2017 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> 677135 T2017 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=nl, timezone=Africa/Blantyre
[junit4:junit4] 2> NOTE: Linux 3.2.0-48-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=3,free=55451200,total=193069056
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestLazyCores, ChaosMonkeySafeLeaderTest, SolrTestCaseJ4Test, TestRandomFaceting, TestDistributedGrouping, OutputWriterTest, CurrencyFieldOpenExchangeTest, SolrRequestParserTest, TermVectorComponentDistributedTest, TestLMJelinekMercerSimilarityFactory, CoreContainerCoreInitFailuresTest, DebugComponentTest, TestSuggestSpellingConverter, TestDynamicFieldResource, TestReloadAndDeleteDocs, IndexBasedSpellCheckerTest, TestJmxIntegration, TestDFRSimilarityFactory, RequiredFieldsTest, SuggesterWFSTTest, DocumentAnalysisRequestHandlerTest, SortByFunctionTest, TestCloudManagedSchemaAddField, TestHashPartitioner, TestSolrXMLSerializer, SimplePostToolTest, TestWordDelimiterFilterFactory, NumericFieldsTest, SolrCoreCheckLockOnStartupTest, OpenCloseCoreStressTest, IndexSchemaRuntimeFieldTest, TestAddFieldRealTimeGet, TestSolr4Spatial, StatsComponentTest, FullSolrCloudDistribCmdsTest, TestStressReorder, TestReload, TestOmitPositions, BadIndexSchemaTest, JSONWriterTest, TestCodecSupport, TestCollationField, HighlighterTest, SpellCheckComponentTest, TestPartialUpdateDeduplication, TestCSVLoader, XmlUpdateRequestHandlerTest, MultiTermTest, DOMUtilTest, SolrIndexConfigTest, TestFastOutputStream, FieldAnalysisRequestHandlerTest, TestRangeQuery, ZkNodePropsTest, PingRequestHandlerTest, TestDefaultSimilarityFactory, TestStressLucene, TestBinaryResponseWriter, TestClassNameShortening, RequestHandlersTest, TestCSVResponseWriter, TestZkChroot, TestRTGBase, TestFiltering, OpenExchangeRatesOrgProviderTest, TestSolrJ, XsltUpdateRequestHandlerTest, TestQueryTypes, TestPropInject, ClusterStateTest, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 28.95s, 1 test, 1 error <<< FAILURES!
[...truncated 462 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:392: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:385: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:437: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1248: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:892: There were test failures: 299 suites, 1290 tests, 1 error, 13 ignored (7 assumptions)
Total time: 43 minutes 26 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