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/10/29 20:57:07 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/ibm-j9-jdk6) - Build # 7995
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/7995/
Java: 32bit/ibm-j9-jdk6 -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:
Expected content type application/octet-stream but got text/html;charset=ISO-8859-1. <html> <head> <meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/> <title>Error 404 Can not find: /duw/b/onenodecollectioncore/update</title> </head> <body> <h2>HTTP ERROR: 404</h2> <p>Problem accessing /duw/b/onenodecollectioncore/update. Reason: <pre> Can not find: /duw/b/onenodecollectioncore/update</pre></p> <hr /><i><small>Powered by Jetty://</small></i> </body> </html>
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Expected content type application/octet-stream but got text/html;charset=ISO-8859-1. <html>
<head>
<meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/>
<title>Error 404 Can not find: /duw/b/onenodecollectioncore/update</title>
</head>
<body>
<h2>HTTP ERROR: 404</h2>
<p>Problem accessing /duw/b/onenodecollectioncore/update. Reason:
<pre> Can not find: /duw/b/onenodecollectioncore/update</pre></p>
<hr /><i><small>Powered by Jetty://</small></i>
</body>
</html>
at __randomizedtesting.SeedInfo.seed([C34518253DFAA800:42A3963D4AA5C83C]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:428)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
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:196)
at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:88)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
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:738)
Build Log:
[...truncated 9726 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4] 2> 848937 T1850 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /duw/b
[junit4] 2> 848940 T1850 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1383075656978
[junit4] 2> 848941 T1850 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 848942 T1851 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 849042 T1850 oasc.ZkTestServer.run start zk server on port:53351
[junit4] 2> 849044 T1850 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 849053 T1857 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6fa06fa0 name:ZooKeeperConnection Watcher:127.0.0.1:53351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 849054 T1850 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 849055 T1850 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 849063 T1850 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 849065 T1859 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31613161 name:ZooKeeperConnection Watcher:127.0.0.1:53351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 849065 T1850 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 849066 T1850 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 849073 T1850 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 849081 T1850 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 849088 T1850 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 849096 T1850 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] 2> 849097 T1850 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 849109 T1850 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] 2> 849110 T1850 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 849119 T1850 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 849120 T1850 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 849127 T1850 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] 2> 849128 T1850 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 849137 T1850 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] 2> 849138 T1850 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 849145 T1850 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] 2> 849147 T1850 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 849155 T1850 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] 2> 849156 T1850 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 849164 T1850 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] 2> 849165 T1850 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 849173 T1850 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] 2> 849175 T1850 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 849184 T1850 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] 2> 849185 T1850 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 849393 T1850 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 849396 T1850 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54139
[junit4] 2> 849397 T1850 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 849398 T1850 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 849399 T1850 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-1383075657233
[junit4] 2> 849400 T1850 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-1383075657233/'
[junit4] 2> 849416 T1850 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1383075657233/solr.xml
[junit4] 2> 849451 T1850 oasc.CoreContainer.<init> New CoreContainer 1032142213
[junit4] 2> 849453 T1850 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1383075657233/]
[junit4] 2> 849455 T1850 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 849456 T1850 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 849457 T1850 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 849458 T1850 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 849459 T1850 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 849460 T1850 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 849460 T1850 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 849461 T1850 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 849462 T1850 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 849463 T1850 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 849464 T1850 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 849466 T1850 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53351/solr
[junit4] 2> 849467 T1850 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 849468 T1850 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 849471 T1870 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dd10dd1 name:ZooKeeperConnection Watcher:127.0.0.1:53351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 849472 T1850 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 849478 T1850 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 849480 T1872 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a557a55 name:ZooKeeperConnection Watcher:127.0.0.1:53351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 849481 T1850 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 849494 T1850 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 849506 T1850 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 849517 T1850 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 849523 T1850 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54139_duw%2Fb
[junit4] 2> 849525 T1850 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54139_duw%2Fb
[junit4] 2> 849536 T1850 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 849551 T1850 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 849559 T1850 oasc.Overseer.start Overseer (id=90641246255972355-127.0.0.1:54139_duw%2Fb-n_0000000000) starting
[junit4] 2> 849569 T1850 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 849581 T1874 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 849583 T1850 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 849593 T1850 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 849599 T1850 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 849609 T1873 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 849612 T1875 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 849612 T1875 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 849615 T1875 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 851132 T1873 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 851137 T1873 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:54139/duw/b",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54139_duw%2Fb",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 851138 T1873 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 851139 T1873 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 851163 T1872 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 851616 T1875 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 851617 T1875 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-1383075657233/collection1
[junit4] 2> 851618 T1875 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 851622 T1875 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 851623 T1875 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 851630 T1875 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-1383075657233/collection1/'
[junit4] 2> 851631 T1875 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-1383075657233/collection1/lib/classes/' to classloader
[junit4] 2> 851632 T1875 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-1383075657233/collection1/lib/README' to classloader
[junit4] 2> 851725 T1875 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 851781 T1875 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 851790 T1875 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 851801 T1875 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 852335 T1875 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 852336 T1875 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 852337 T1875 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 852346 T1875 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 852351 T1875 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 852391 T1875 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 852402 T1875 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 852411 T1875 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 852416 T1875 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 852417 T1875 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 852418 T1875 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 852423 T1875 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 852424 T1875 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 852425 T1875 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 852426 T1875 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-1383075657233/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/control/data/
[junit4] 2> 852427 T1875 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@78897889
[junit4] 2> 852428 T1875 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/control/data
[junit4] 2> 852429 T1875 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/control/data/index/
[junit4] 2> 852429 T1875 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 852430 T1875 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/control/data/index
[junit4] 2> 852430 T1875 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=23.0009765625, floorSegmentMB=0.3427734375, forceMergeDeletesPctAllowed=22.204155294018406, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.817623444006441
[junit4] 2> 852432 T1875 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59745974 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@734e734e),segFN=segments_1,generation=1}
[junit4] 2> 852433 T1875 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 852440 T1875 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 852441 T1875 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 852442 T1875 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 852442 T1875 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 852443 T1875 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 852444 T1875 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 852445 T1875 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 852446 T1875 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 852447 T1875 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 852448 T1875 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 852449 T1875 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 852466 T1875 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 852467 T1875 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 852467 T1875 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 852468 T1875 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 852470 T1875 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 852474 T1875 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 852475 T1875 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 852476 T1875 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=33, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.31315673329289384]
[junit4] 2> 852477 T1875 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59745974 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@734e734e),segFN=segments_1,generation=1}
[junit4] 2> 852478 T1875 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 852479 T1875 oass.SolrIndexSearcher.<init> Opening Searcher@3aa03aa main
[junit4] 2> 852485 T1876 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3aa03aa main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 852487 T1875 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 852487 T1875 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54139/duw/b collection:control_collection shard:shard1
[junit4] 2> 852491 T1875 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 852533 T1875 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 852542 T1875 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 852543 T1875 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 852544 T1875 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54139/duw/b/collection1/
[junit4] 2> 852544 T1875 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 852545 T1875 oasc.SyncStrategy.syncToMe http://127.0.0.1:54139/duw/b/collection1/ has no replicas
[junit4] 2> 852545 T1875 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54139/duw/b/collection1/ shard1
[junit4] 2> 852546 T1875 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 852687 T1873 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 852721 T1872 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 852768 T1875 oasc.ZkController.register We are http://127.0.0.1:54139/duw/b/collection1/ and leader is http://127.0.0.1:54139/duw/b/collection1/
[junit4] 2> 852769 T1875 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54139/duw/b
[junit4] 2> 852769 T1875 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 852770 T1875 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 852771 T1875 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 852780 T1875 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 852783 T1850 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 852783 T1850 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 852786 T1850 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 852788 T1879 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58e458e4 name:ZooKeeperConnection Watcher:127.0.0.1:53351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 852789 T1850 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 852792 T1850 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 852800 T1850 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 852965 T1850 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 852967 T1850 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:38889
[junit4] 2> 852968 T1850 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 852969 T1850 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 852970 T1850 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-1383075660838
[junit4] 2> 852970 T1850 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-1383075660838/'
[junit4] 2> 852982 T1850 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1383075660838/solr.xml
[junit4] 2> 853042 T1850 oasc.CoreContainer.<init> New CoreContainer 1827630319
[junit4] 2> 853043 T1850 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1383075660838/]
[junit4] 2> 853045 T1850 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 853045 T1850 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 853046 T1850 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 853047 T1850 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 853048 T1850 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 853048 T1850 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 853049 T1850 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 853050 T1850 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 853051 T1850 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 853052 T1850 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 853054 T1850 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 853056 T1850 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53351/solr
[junit4] 2> 853057 T1850 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 853058 T1850 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 853061 T1890 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51ee51ee name:ZooKeeperConnection Watcher:127.0.0.1:53351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 853061 T1850 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 853067 T1850 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 853069 T1892 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3d6b3d6b name:ZooKeeperConnection Watcher:127.0.0.1:53351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 853070 T1850 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 853085 T1850 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 854096 T1850 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38889_duw%2Fb
[junit4] 2> 854098 T1850 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38889_duw%2Fb
[junit4] 2> 854108 T1872 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 854109 T1879 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 854109 T1892 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 854123 T1893 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 854124 T1893 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 854126 T1893 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 854244 T1873 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 854247 T1873 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:54139/duw/b",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54139_duw%2Fb",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 854257 T1873 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:38889/duw/b",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:38889_duw%2Fb",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 854258 T1873 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 854259 T1873 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 854271 T1879 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 854271 T1872 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 854271 T1892 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 855127 T1893 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 855128 T1893 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-1383075660838/collection1
[junit4] 2> 855128 T1893 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 855133 T1893 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 855134 T1893 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 855139 T1893 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-1383075660838/collection1/'
[junit4] 2> 855142 T1893 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-1383075660838/collection1/lib/classes/' to classloader
[junit4] 2> 855143 T1893 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-1383075660838/collection1/lib/README' to classloader
[junit4] 2> 855217 T1893 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 855254 T1893 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 855261 T1893 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 855269 T1893 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 855655 T1893 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 855655 T1893 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 855656 T1893 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 855662 T1893 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 855665 T1893 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 855734 T1893 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 855748 T1893 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 855762 T1893 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 855770 T1893 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 855771 T1893 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 855773 T1893 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 855780 T1893 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 855782 T1893 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 855783 T1893 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 855784 T1893 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-1383075660838/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty1/
[junit4] 2> 855785 T1893 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@78897889
[junit4] 2> 855788 T1893 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty1
[junit4] 2> 855789 T1893 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty1/index/
[junit4] 2> 855790 T1893 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 855792 T1893 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty1/index
[junit4] 2> 855793 T1893 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=23.0009765625, floorSegmentMB=0.3427734375, forceMergeDeletesPctAllowed=22.204155294018406, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.817623444006441
[junit4] 2> 855795 T1893 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a104a10 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6b9c6b9c),segFN=segments_1,generation=1}
[junit4] 2> 855796 T1893 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 855806 T1893 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 855806 T1893 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 855807 T1893 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 855807 T1893 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 855808 T1893 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 855809 T1893 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 855809 T1893 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 855810 T1893 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 855811 T1893 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 855812 T1893 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 855812 T1893 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 855813 T1893 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 855814 T1893 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 855815 T1893 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 855815 T1893 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 855817 T1893 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 855820 T1893 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 855821 T1893 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 855821 T1893 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=33, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.31315673329289384]
[junit4] 2> 855822 T1893 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a104a10 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6b9c6b9c),segFN=segments_1,generation=1}
[junit4] 2> 855823 T1893 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 855823 T1893 oass.SolrIndexSearcher.<init> Opening Searcher@109a109a main
[junit4] 2> 855831 T1894 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@109a109a main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 855834 T1893 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 855835 T1893 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:38889/duw/b collection:collection1 shard:shard1
[junit4] 2> 855839 T1893 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 855874 T1893 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 855886 T1893 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 855887 T1893 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 855888 T1893 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:38889/duw/b/collection1/
[junit4] 2> 855890 T1893 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 855891 T1893 oasc.SyncStrategy.syncToMe http://127.0.0.1:38889/duw/b/collection1/ has no replicas
[junit4] 2> 855893 T1893 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38889/duw/b/collection1/ shard1
[junit4] 2> 855894 T1893 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 857307 T1873 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 857330 T1879 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 857330 T1872 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 857331 T1892 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 857346 T1893 oasc.ZkController.register We are http://127.0.0.1:38889/duw/b/collection1/ and leader is http://127.0.0.1:38889/duw/b/collection1/
[junit4] 2> 857347 T1893 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38889/duw/b
[junit4] 2> 857348 T1893 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 857348 T1893 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 857349 T1893 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 857353 T1893 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 857356 T1850 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 857357 T1850 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 857582 T1850 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 857584 T1850 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56498
[junit4] 2> 857585 T1850 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 857586 T1850 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 857587 T1850 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-1383075665397
[junit4] 2> 857587 T1850 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-1383075665397/'
[junit4] 2> 857599 T1850 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1383075665397/solr.xml
[junit4] 2> 857634 T1850 oasc.CoreContainer.<init> New CoreContainer 1930916631
[junit4] 2> 857635 T1850 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1383075665397/]
[junit4] 2> 857636 T1850 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 857637 T1850 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 857637 T1850 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 857638 T1850 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 857639 T1850 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 857640 T1850 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 857641 T1850 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 857642 T1850 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 857643 T1850 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 857646 T1850 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 857647 T1850 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 857649 T1850 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53351/solr
[junit4] 2> 857651 T1850 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 857653 T1850 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 857655 T1906 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4a014a01 name:ZooKeeperConnection Watcher:127.0.0.1:53351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 857656 T1850 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 857672 T1850 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 857674 T1908 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@25942594 name:ZooKeeperConnection Watcher:127.0.0.1:53351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 857674 T1850 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 857690 T1850 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 858704 T1850 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56498_duw%2Fb
[junit4] 2> 858709 T1850 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56498_duw%2Fb
[junit4] 2> 858729 T1908 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 858731 T1879 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 858732 T1872 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 858734 T1892 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 858754 T1909 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 858755 T1909 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 858758 T1909 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 858862 T1873 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 858867 T1873 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:38889/duw/b",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:38889_duw%2Fb",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 858886 T1873 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:56498/duw/b",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:56498_duw%2Fb",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 858888 T1873 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 858889 T1873 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 858903 T1879 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 858904 T1892 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 858904 T1872 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 858905 T1908 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 859759 T1909 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 859760 T1909 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-1383075665397/collection1
[junit4] 2> 859760 T1909 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 859763 T1909 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 859764 T1909 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 859770 T1909 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-1383075665397/collection1/'
[junit4] 2> 859772 T1909 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-1383075665397/collection1/lib/classes/' to classloader
[junit4] 2> 859787 T1909 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-1383075665397/collection1/lib/README' to classloader
[junit4] 2> 859853 T1909 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 859914 T1909 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 859918 T1909 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 859929 T1909 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 860404 T1909 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 860405 T1909 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 860406 T1909 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 860411 T1909 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 860415 T1909 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 860455 T1909 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 860464 T1909 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 860473 T1909 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 860477 T1909 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 860478 T1909 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 860478 T1909 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 860483 T1909 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 860484 T1909 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 860484 T1909 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 860485 T1909 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-1383075665397/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty2/
[junit4] 2> 860486 T1909 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@78897889
[junit4] 2> 860487 T1909 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty2
[junit4] 2> 860487 T1909 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty2/index/
[junit4] 2> 860488 T1909 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 860501 T1909 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty2/index
[junit4] 2> 860501 T1909 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=23.0009765625, floorSegmentMB=0.3427734375, forceMergeDeletesPctAllowed=22.204155294018406, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.817623444006441
[junit4] 2> 860502 T1909 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@63e463e4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@38863886),segFN=segments_1,generation=1}
[junit4] 2> 860503 T1909 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 860511 T1909 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 860512 T1909 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 860513 T1909 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 860513 T1909 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 860514 T1909 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 860514 T1909 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 860515 T1909 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 860516 T1909 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 860516 T1909 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 860518 T1909 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 860519 T1909 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 860520 T1909 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 860521 T1909 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 860522 T1909 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 860523 T1909 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 860526 T1909 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 860530 T1909 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 860531 T1909 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 860533 T1909 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=33, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.31315673329289384]
[junit4] 2> 860534 T1909 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@63e463e4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@38863886),segFN=segments_1,generation=1}
[junit4] 2> 860535 T1909 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 860535 T1909 oass.SolrIndexSearcher.<init> Opening Searcher@73547354 main
[junit4] 2> 860543 T1910 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@73547354 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 860548 T1909 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 860549 T1909 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56498/duw/b collection:collection1 shard:shard2
[junit4] 2> 860553 T1909 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 860582 T1909 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 860590 T1909 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 860590 T1909 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 860591 T1909 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:56498/duw/b/collection1/
[junit4] 2> 860592 T1909 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 860592 T1909 oasc.SyncStrategy.syncToMe http://127.0.0.1:56498/duw/b/collection1/ has no replicas
[junit4] 2> 860593 T1909 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:56498/duw/b/collection1/ shard2
[junit4] 2> 860593 T1909 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 861940 T1873 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 861972 T1879 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 861973 T1908 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 861972 T1872 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 861974 T1892 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 861984 T1909 oasc.ZkController.register We are http://127.0.0.1:56498/duw/b/collection1/ and leader is http://127.0.0.1:56498/duw/b/collection1/
[junit4] 2> 861985 T1909 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56498/duw/b
[junit4] 2> 861985 T1909 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 861986 T1909 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 861986 T1909 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 861992 T1909 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 861996 T1850 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 861997 T1850 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 862203 T1850 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 862204 T1850 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:34738
[junit4] 2> 862205 T1850 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 862206 T1850 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 862207 T1850 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1383075670036
[junit4] 2> 862207 T1850 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1383075670036/'
[junit4] 2> 862219 T1850 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1383075670036/solr.xml
[junit4] 2> 862266 T1850 oasc.CoreContainer.<init> New CoreContainer 925185829
[junit4] 2> 862267 T1850 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1383075670036/]
[junit4] 2> 862268 T1850 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 862269 T1850 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 862269 T1850 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 862270 T1850 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 862271 T1850 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 862272 T1850 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 862272 T1850 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 862273 T1850 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 862274 T1850 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 862275 T1850 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 862276 T1850 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 862278 T1850 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53351/solr
[junit4] 2> 862279 T1850 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 862280 T1850 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 862282 T1922 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24c024c0 name:ZooKeeperConnection Watcher:127.0.0.1:53351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 862283 T1850 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 862288 T1850 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 862290 T1924 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63116311 name:ZooKeeperConnection Watcher:127.0.0.1:53351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 862291 T1850 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 862316 T1850 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 863329 T1850 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34738_duw%2Fb
[junit4] 2> 863334 T1850 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34738_duw%2Fb
[junit4] 2> 863348 T1908 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 863348 T1879 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 863350 T1872 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 863350 T1892 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 863351 T1924 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 863363 T1925 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 863364 T1925 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 863366 T1925 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 863502 T1873 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 863520 T1873 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:56498/duw/b",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:56498_duw%2Fb",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 863606 T1873 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:34738/duw/b",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:34738_duw%2Fb",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 863607 T1873 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 863609 T1873 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 863622 T1879 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 863622 T1892 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 863623 T1924 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 863623 T1908 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 863624 T1872 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 864367 T1925 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 864368 T1925 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1383075670036/collection1
[junit4] 2> 864369 T1925 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 864372 T1925 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 864373 T1925 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 864378 T1925 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1383075670036/collection1/'
[junit4] 2> 864381 T1925 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-1383075670036/collection1/lib/classes/' to classloader
[junit4] 2> 864381 T1925 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-1383075670036/collection1/lib/README' to classloader
[junit4] 2> 864426 T1925 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 864483 T1925 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 864487 T1925 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 864494 T1925 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 864935 T1925 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 864936 T1925 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 864937 T1925 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 864942 T1925 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 864945 T1925 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 864995 T1925 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 865002 T1925 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 865023 T1925 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 865027 T1925 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 865028 T1925 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 865028 T1925 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 865032 T1925 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 865033 T1925 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 865034 T1925 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 865034 T1925 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1383075670036/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty3/
[junit4] 2> 865035 T1925 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@78897889
[junit4] 2> 865036 T1925 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty3
[junit4] 2> 865037 T1925 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty3/index/
[junit4] 2> 865037 T1925 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 865038 T1925 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1383075656978/jetty3/index
[junit4] 2> 865038 T1925 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=23.0009765625, floorSegmentMB=0.3427734375, forceMergeDeletesPctAllowed=22.204155294018406, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.817623444006441
[junit4] 2> 865039 T1925 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@28682868 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac81ac8),segFN=segments_1,generation=1}
[junit4] 2> 865040 T1925 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 865048 T1925 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 865049 T1925 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 865049 T1925 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 865050 T1925 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 865051 T1925 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 865052 T1925 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 865053 T1925 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 865054 T1925 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 865055 T1925 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 865056 T1925 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 865057 T1925 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 865058 T1925 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 865059 T1925 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 865060 T1925 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 865061 T1925 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 865062 T1925 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 865065 T1925 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 865066 T1925 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 865067 T1925 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=33, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.31315673329289384]
[junit4] 2> 865068 T1925 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@28682868 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac81ac8),segFN=segments_1,generation=1}
[junit4] 2> 865068 T1925 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 865069 T1925 oass.SolrIndexSearcher.<init> Opening Searcher@3c873c87 main
[junit4] 2> 865075 T1926 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3c873c87 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 865078 T1925 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 865079 T1925 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:34738/duw/b collection:collection1 shard:shard1
[junit4] 2> 865099 T1925 oasc.ZkController.register We are http://127.0.0.1:34738/duw/b/collection1/ and leader is http://127.0.0.1:38889/duw/b/collection1/
[junit4] 2> 865099 T1925 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34738/duw/b
[junit4] 2> 865100 T1925 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 865100 T1925 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C8283 name=collection1 org.apache.solr.core.SolrCore@e500e50 url=http://127.0.0.1:34738/duw/b/collection1 node=127.0.0.1:34738_duw%2Fb C8283_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:34738/duw/b, core=collection1, node_name=127.0.0.1:34738_duw%2Fb}
[junit4] 2> 865101 T1927 C8283 P34738 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 865102 T1927 C8283 P34738 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 865102 T1927 C8283 P34738 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 865102 T1925 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 865103 T1927 C8283 P34738 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 865106 T1850 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 865106 T1850 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[...truncated too long message...]
nge":"80000000-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{"core_node1":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:38889/duw/b",
[junit4] 1> "core":"onenodecollectioncore",
[junit4] 1> "roles":"none",
[junit4] 1> "node_name":"127.0.0.1:38889_duw%2Fb",
[junit4] 1> "leader":"true"}}}},
[junit4] 1> "maxShardsPerNode":"1",
[junit4] 1> "autoCreated":"true",
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "replicationFactor":"1"},
[junit4] 1> "collection1":{
[junit4] 1> "shards":{
[junit4] 1> "shard1":{
[junit4] 1> "range":"80000000-ffffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{
[junit4] 1> "core_node1":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:38889/duw/b",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:38889_duw%2Fb",
[junit4] 1> "leader":"true"},
[junit4] 1> "core_node3":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:34738/duw/b",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:34738_duw%2Fb"}}},
[junit4] 1> "shard2":{
[junit4] 1> "range":"0-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{
[junit4] 1> "core_node2":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:56498/duw/b",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:56498_duw%2Fb",
[junit4] 1> "leader":"true"},
[junit4] 1> "core_node4":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:48719/duw/b",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:48719_duw%2Fb"}}}},
[junit4] 1> "maxShardsPerNode":"1",
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "autoCreated":"true",
[junit4] 1> "replicationFactor":"1"}}
[junit4] 1> /zookeeper (1)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZk2Test -Dtests.method=testDistribSearch -Dtests.seed=C34518253DFAA800 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ms -Dtests.timezone=MIT -Dtests.file.encoding=UTF-8
[junit4] ERROR 33.8s J1 | BasicDistributedZk2Test.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Expected content type application/octet-stream but got text/html;charset=ISO-8859-1. <html>
[junit4] > <head>
[junit4] > <meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/>
[junit4] > <title>Error 404 Can not find: /duw/b/onenodecollectioncore/update</title>
[junit4] > </head>
[junit4] > <body>
[junit4] > <h2>HTTP ERROR: 404</h2>
[junit4] > <p>Problem accessing /duw/b/onenodecollectioncore/update. Reason:
[junit4] > <pre> Can not find: /duw/b/onenodecollectioncore/update</pre></p>
[junit4] > <hr /><i><small>Powered by Jetty://</small></i>
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] >
[junit4] > </body>
[junit4] > </html>
[junit4] > at __randomizedtesting.SeedInfo.seed([C34518253DFAA800:42A3963D4AA5C83C]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:428)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
[junit4] > at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
[junit4] > at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
[junit4] > at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
[junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:196)
[junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:88)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:738)
[junit4] 2> 882704 T1850 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 33785 T1849 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> 882757 T1924 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 883869 T1941 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene45: {}, docValues:{}, sim=DefaultSimilarity, locale=ms, timezone=MIT
[junit4] 2> NOTE: Linux 3.8.0-32-generic x86/IBM Corporation 1.6.0 (32-bit)/cpus=8,threads=2,free=37254608,total=69794304
[junit4] 2> NOTE: All tests run in this JVM: [SolrPluginUtilsTest, CustomCollectionTest, TestAddFieldRealTimeGet, TestOmitPositions, TestCollapseQParserPlugin, IndexSchemaRuntimeFieldTest, MinimalSchemaTest, TestNumberUtils, DistanceFunctionTest, TestRTGBase, TestFastWriter, TestDynamicFieldCollectionResource, HdfsUnloadDistributedZkTest, TestSolrQueryParserDefaultOperatorResource, TermVectorComponentDistributedTest, TestFastOutputStream, ChaosMonkeySafeLeaderTest, NotRequiredUniqueKeyTest, TestStressRecovery, RAMDirectoryFactoryTest, TestRandomFaceting, SimplePostToolTest, TestFieldTypeCollectionResource, TestFoldingMultitermQuery, TestSchemaNameResource, TestSolrXmlPersistence, TestDynamicFieldResource, BadIndexSchemaTest, XmlUpdateRequestHandlerTest, FieldAnalysisRequestHandlerTest, CoreMergeIndexesAdminHandlerTest, TestBinaryResponseWriter, SuggesterTSTTest, ShardRoutingCustomTest, TestCollationField, SolrCoreCheckLockOnStartupTest, HdfsDirectoryTest, CoreAdminCreateDiscoverTest, TestFieldTypeResource, TestCopyFieldCollectionResource, TestSolrXml, CachingDirectoryFactoryTest, AlternateDirectoryTest, DirectUpdateHandlerTest, TestQuerySenderListener, TestSolrDeletionPolicy2, TestRangeQuery, TestQueryTypes, XsltUpdateRequestHandlerTest, HighlighterConfigTest, NoCacheHeaderTest, CollectionsAPIDistributedZkTest, SortByFunctionTest, StandardRequestHandlerTest, BlockDirectoryTest, TestCodecSupport, TestFuzzyAnalyzedSuggestions, LeaderElectionIntegrationTest, BadCopyFieldTest, ZkNodePropsTest, UniqFieldsUpdateProcessorFactoryTest, TestSolrJ, TestIndexingPerformance, TestIBSimilarityFactory, DocValuesMissingTest, BasicDistributedZk2Test]
[junit4] Completed on J1 in 35.08s, 1 test, 1 error <<< FAILURES!
[...truncated 561 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:428: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:421: 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:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:483: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1263: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:906: There were test failures: 330 suites, 1457 tests, 1 error, 35 ignored (6 assumptions)
Total time: 56 minutes 36 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/ibm-j9-jdk6 -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