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/07/19 12:26:29 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/ibm-j9-jdk6) - Build # 6556
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/6556/
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:
Server at http://127.0.0.1:56562/u/il/onenodecollectioncore returned non ok status:404, message:Can not find: /u/il/onenodecollectioncore/update
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:56562/u/il/onenodecollectioncore returned non ok status:404, message:Can not find: /u/il/onenodecollectioncore/update
at __randomizedtesting.SeedInfo.seed([9F40A5078EB8081B:1EA62B1FF9E76827]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java: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 9209 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4] 2> 709525 T2880 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /u/il
[junit4] 2> 709529 T2880 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1374228618310
[junit4] 2> 709530 T2880 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 709531 T2881 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 709631 T2880 oasc.ZkTestServer.run start zk server on port:51997
[junit4] 2> 709633 T2880 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 709637 T2887 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54e554e5 name:ZooKeeperConnection Watcher:127.0.0.1:51997 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 709637 T2880 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 709638 T2880 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 709645 T2880 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 709646 T2889 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16841684 name:ZooKeeperConnection Watcher:127.0.0.1:51997/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 709647 T2880 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 709648 T2880 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 709655 T2880 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 709663 T2880 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 709669 T2880 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 709676 T2880 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> 709678 T2880 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 709688 T2880 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> 709689 T2880 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 709697 T2880 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> 709699 T2880 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 709707 T2880 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> 709708 T2880 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 709716 T2880 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> 709717 T2880 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 709724 T2880 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> 709725 T2880 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 709733 T2880 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> 709734 T2880 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 709741 T2880 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> 709743 T2880 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 709750 T2880 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> 709751 T2880 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 709908 T2880 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 709912 T2880 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54750
[junit4] 2> 709913 T2880 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 709913 T2880 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 709914 T2880 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374228618541
[junit4] 2> 709915 T2880 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374228618541/'
[junit4] 2> 709926 T2880 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374228618541/solr.xml
[junit4] 2> 709962 T2880 oasc.CoreContainer.<init> New CoreContainer 1195329343
[junit4] 2> 709963 T2880 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374228618541/]
[junit4] 2> 709964 T2880 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 709965 T2880 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 709966 T2880 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 709966 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 709967 T2880 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 709968 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 709969 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 709969 T2880 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 709970 T2880 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 709971 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 709977 T2880 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 709979 T2880 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51997/solr
[junit4] 2> 709980 T2880 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 709981 T2880 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 709984 T2900 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9a609a6 name:ZooKeeperConnection Watcher:127.0.0.1:51997 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 709985 T2880 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 709989 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 709996 T2880 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 709999 T2902 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3be43be4 name:ZooKeeperConnection Watcher:127.0.0.1:51997/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 710000 T2880 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 710004 T2880 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 710015 T2880 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 710047 T2880 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 710056 T2880 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54750_u%2Fil
[junit4] 2> 710060 T2880 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54750_u%2Fil
[junit4] 2> 710086 T2880 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 710129 T2880 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 710145 T2880 oasc.Overseer.start Overseer (id=90061446729826307-127.0.0.1:54750_u%2Fil-n_0000000000) starting
[junit4] 2> 710160 T2880 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 710176 T2904 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 710180 T2880 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 710191 T2880 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 710199 T2880 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 710213 T2903 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 710218 T2905 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 710219 T2905 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 710222 T2905 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 711727 T2903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 711731 T2903 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "shard_state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:54750/u/il",
[junit4] 2> "state":"down",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "node_name":"127.0.0.1:54750_u%2Fil",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard_range":null,
[junit4] 2> "roles":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "shard":null,
[junit4] 2> "core":"collection1"}
[junit4] 2> 711732 T2903 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4] 2> 711733 T2903 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 711744 T2902 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> 712223 T2905 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 712224 T2905 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374228618541/collection1
[junit4] 2> 712225 T2905 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 712227 T2905 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 712228 T2905 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 712255 T2905 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374228618541/collection1/'
[junit4] 2> 712257 T2905 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374228618541/collection1/lib/README' to classloader
[junit4] 2> 712258 T2905 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374228618541/collection1/lib/classes/' to classloader
[junit4] 2> 712305 T2905 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 712349 T2905 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 712355 T2905 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 712366 T2905 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 712801 T2905 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 712802 T2905 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 712803 T2905 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 712808 T2905 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 712811 T2905 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 712848 T2905 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 712855 T2905 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 712861 T2905 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 712865 T2905 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 712866 T2905 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 712867 T2905 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 712870 T2905 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 712871 T2905 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 712872 T2905 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 712872 T2905 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374228618541/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/control/data/
[junit4] 2> 712873 T2905 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2bbb2bbb
[junit4] 2> 712874 T2905 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/control/data
[junit4] 2> 712875 T2905 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/control/data/index/
[junit4] 2> 712875 T2905 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 712876 T2905 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/control/data/index
[junit4] 2> 712879 T2905 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3e8e3e8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@65dc65dc),segFN=segments_1,generation=1}
[junit4] 2> 712880 T2905 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 712886 T2905 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 712886 T2905 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 712887 T2905 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 712888 T2905 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 712889 T2905 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 712889 T2905 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 712890 T2905 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 712891 T2905 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 712891 T2905 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 712893 T2905 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 712895 T2905 oass.SolrIndexSearcher.<init> Opening Searcher@1e051e05 main
[junit4] 2> 712896 T2905 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 712897 T2905 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 712902 T2906 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e051e05 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 712905 T2905 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 712906 T2905 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54750/u/il collection:control_collection shard:shard1
[junit4] 2> 712906 T2905 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 712914 T2905 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 712958 T2905 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 712966 T2905 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 712967 T2905 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 712967 T2905 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54750/u/il/collection1/
[junit4] 2> 712968 T2905 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 712969 T2905 oasc.SyncStrategy.syncToMe http://127.0.0.1:54750/u/il/collection1/ has no replicas
[junit4] 2> 712970 T2905 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54750/u/il/collection1/ shard1
[junit4] 2> 712970 T2905 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 713258 T2903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 713287 T2902 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> 713343 T2905 oasc.ZkController.register We are http://127.0.0.1:54750/u/il/collection1/ and leader is http://127.0.0.1:54750/u/il/collection1/
[junit4] 2> 713344 T2905 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54750/u/il
[junit4] 2> 713345 T2905 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 713346 T2905 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 713348 T2905 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 713356 T2905 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 713361 T2880 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 713363 T2880 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 713364 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 713371 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 713373 T2880 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 713375 T2909 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34383438 name:ZooKeeperConnection Watcher:127.0.0.1:51997/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 713375 T2880 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 713378 T2880 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 713387 T2880 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 713566 T2880 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 713568 T2880 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36660
[junit4] 2> 713570 T2880 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 713571 T2880 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 713572 T2880 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374228622168
[junit4] 2> 713573 T2880 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374228622168/'
[junit4] 2> 713586 T2880 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374228622168/solr.xml
[junit4] 2> 713627 T2880 oasc.CoreContainer.<init> New CoreContainer 1880715289
[junit4] 2> 713628 T2880 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374228622168/]
[junit4] 2> 713630 T2880 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 713631 T2880 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 713631 T2880 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 713632 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 713633 T2880 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 713634 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 713635 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 713635 T2880 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 713636 T2880 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 713637 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 713644 T2880 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 713646 T2880 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51997/solr
[junit4] 2> 713647 T2880 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 713648 T2880 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 713654 T2920 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e854e85 name:ZooKeeperConnection Watcher:127.0.0.1:51997 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 713661 T2880 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 713668 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 713677 T2880 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 713690 T2922 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b8e5b8e name:ZooKeeperConnection Watcher:127.0.0.1:51997/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 713691 T2880 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 713709 T2880 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 714725 T2880 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36660_u%2Fil
[junit4] 2> 714728 T2880 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36660_u%2Fil
[junit4] 2> 714739 T2909 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 714739 T2902 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 714740 T2902 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 714741 T2922 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 714761 T2923 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 714762 T2923 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 714765 T2923 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 714811 T2903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 714817 T2903 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "shard_state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:54750/u/il",
[junit4] 2> "state":"active",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "node_name":"127.0.0.1:54750_u%2Fil",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard_range":null,
[junit4] 2> "roles":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"collection1"}
[junit4] 2> 714833 T2903 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "shard_state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:36660/u/il",
[junit4] 2> "state":"down",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "node_name":"127.0.0.1:36660_u%2Fil",
[junit4] 2> "numShards":"2",
[junit4] 2> "shard_range":null,
[junit4] 2> "roles":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard":null,
[junit4] 2> "core":"collection1"}
[junit4] 2> 714833 T2903 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4] 2> 714834 T2903 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 714845 T2909 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> 714845 T2902 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> 714846 T2922 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> 715765 T2923 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 715766 T2923 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374228622168/collection1
[junit4] 2> 715767 T2923 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 715770 T2923 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 715771 T2923 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 715775 T2923 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374228622168/collection1/'
[junit4] 2> 715777 T2923 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374228622168/collection1/lib/README' to classloader
[junit4] 2> 715778 T2923 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374228622168/collection1/lib/classes/' to classloader
[junit4] 2> 715866 T2923 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 715904 T2923 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 715913 T2923 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 715922 T2923 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 716320 T2923 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 716320 T2923 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 716321 T2923 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 716327 T2923 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 716330 T2923 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 716390 T2923 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 716417 T2923 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 716425 T2923 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 716430 T2923 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 716430 T2923 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 716431 T2923 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 716437 T2923 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 716438 T2923 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 716438 T2923 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 716439 T2923 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374228622168/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty1/
[junit4] 2> 716440 T2923 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2bbb2bbb
[junit4] 2> 716443 T2923 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty1
[junit4] 2> 716444 T2923 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty1/index/
[junit4] 2> 716444 T2923 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 716446 T2923 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty1/index
[junit4] 2> 716450 T2923 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@cd40cd4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@cfe0cfe),segFN=segments_1,generation=1}
[junit4] 2> 716451 T2923 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 716465 T2923 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 716466 T2923 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 716467 T2923 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 716468 T2923 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 716469 T2923 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 716469 T2923 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 716470 T2923 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 716471 T2923 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 716472 T2923 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 716473 T2923 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 716476 T2923 oass.SolrIndexSearcher.<init> Opening Searcher@32d532d5 main
[junit4] 2> 716477 T2923 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 716478 T2923 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 716489 T2924 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@32d532d5 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 716497 T2923 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 716498 T2923 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36660/u/il collection:collection1 shard:shard1
[junit4] 2> 716499 T2923 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 716508 T2923 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 716535 T2923 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 716542 T2923 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 716543 T2923 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 716543 T2923 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36660/u/il/collection1/
[junit4] 2> 716544 T2923 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 716544 T2923 oasc.SyncStrategy.syncToMe http://127.0.0.1:36660/u/il/collection1/ has no replicas
[junit4] 2> 716545 T2923 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36660/u/il/collection1/ shard1
[junit4] 2> 716545 T2923 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 717883 T2903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 717911 T2902 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> 717912 T2922 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> 717912 T2909 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> 717921 T2923 oasc.ZkController.register We are http://127.0.0.1:36660/u/il/collection1/ and leader is http://127.0.0.1:36660/u/il/collection1/
[junit4] 2> 717921 T2923 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36660/u/il
[junit4] 2> 717922 T2923 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 717923 T2923 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 717923 T2923 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 717927 T2923 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 717930 T2880 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 717931 T2880 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 717933 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 718122 T2880 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 718124 T2880 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56562
[junit4] 2> 718126 T2880 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 718127 T2880 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 718128 T2880 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374228626720
[junit4] 2> 718128 T2880 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374228626720/'
[junit4] 2> 718143 T2880 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374228626720/solr.xml
[junit4] 2> 718180 T2880 oasc.CoreContainer.<init> New CoreContainer 903099860
[junit4] 2> 718181 T2880 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374228626720/]
[junit4] 2> 718183 T2880 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 718184 T2880 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 718184 T2880 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 718185 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 718186 T2880 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 718187 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 718187 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 718188 T2880 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 718189 T2880 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 718190 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 718196 T2880 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 718198 T2880 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51997/solr
[junit4] 2> 718199 T2880 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 718200 T2880 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 718202 T2936 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a681a68 name:ZooKeeperConnection Watcher:127.0.0.1:51997 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 718203 T2880 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 718207 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 718214 T2880 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 718217 T2938 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f044f04 name:ZooKeeperConnection Watcher:127.0.0.1:51997/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 718218 T2880 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 718257 T2880 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 719269 T2880 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56562_u%2Fil
[junit4] 2> 719271 T2880 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56562_u%2Fil
[junit4] 2> 719278 T2922 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 719278 T2909 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 719280 T2938 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 719283 T2902 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 719284 T2902 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 719293 T2909 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 719296 T2922 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 719308 T2939 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 719309 T2939 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 719311 T2939 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 719442 T2903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 719446 T2903 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "shard_state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:36660/u/il",
[junit4] 2> "state":"active",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "node_name":"127.0.0.1:36660_u%2Fil",
[junit4] 2> "numShards":"2",
[junit4] 2> "shard_range":null,
[junit4] 2> "roles":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"collection1"}
[junit4] 2> 719460 T2903 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "shard_state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:56562/u/il",
[junit4] 2> "state":"down",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "node_name":"127.0.0.1:56562_u%2Fil",
[junit4] 2> "numShards":"2",
[junit4] 2> "shard_range":null,
[junit4] 2> "roles":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard":null,
[junit4] 2> "core":"collection1"}
[junit4] 2> 719461 T2903 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 719461 T2903 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 719475 T2909 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> 719475 T2922 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> 719476 T2902 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> 719478 T2938 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> 720312 T2939 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 720313 T2939 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374228626720/collection1
[junit4] 2> 720313 T2939 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 720316 T2939 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 720316 T2939 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 720320 T2939 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374228626720/collection1/'
[junit4] 2> 720322 T2939 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374228626720/collection1/lib/README' to classloader
[junit4] 2> 720323 T2939 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374228626720/collection1/lib/classes/' to classloader
[junit4] 2> 720361 T2939 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 720412 T2939 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 720416 T2939 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 720424 T2939 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 720836 T2939 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 720836 T2939 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 720837 T2939 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 720843 T2939 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 720847 T2939 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 720908 T2939 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 720915 T2939 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 720924 T2939 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 720929 T2939 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 720930 T2939 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 720930 T2939 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 720934 T2939 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 720935 T2939 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 720936 T2939 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 720937 T2939 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374228626720/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty2/
[junit4] 2> 720939 T2939 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2bbb2bbb
[junit4] 2> 720941 T2939 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty2
[junit4] 2> 720942 T2939 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty2/index/
[junit4] 2> 720943 T2939 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 720945 T2939 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty2/index
[junit4] 2> 720949 T2939 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@10d410d4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@eff0eff),segFN=segments_1,generation=1}
[junit4] 2> 720951 T2939 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 720963 T2939 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 720964 T2939 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 720964 T2939 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 720965 T2939 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 720966 T2939 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 720967 T2939 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 720968 T2939 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 720968 T2939 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 720969 T2939 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 720971 T2939 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 720973 T2939 oass.SolrIndexSearcher.<init> Opening Searcher@6aa16aa1 main
[junit4] 2> 720974 T2939 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 720975 T2939 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 720981 T2940 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6aa16aa1 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 720985 T2939 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 720986 T2939 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56562/u/il collection:collection1 shard:shard2
[junit4] 2> 720986 T2939 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 720994 T2939 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 721020 T2939 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 721029 T2939 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 721030 T2939 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 721031 T2939 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:56562/u/il/collection1/
[junit4] 2> 721031 T2939 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 721032 T2939 oasc.SyncStrategy.syncToMe http://127.0.0.1:56562/u/il/collection1/ has no replicas
[junit4] 2> 721033 T2939 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:56562/u/il/collection1/ shard2
[junit4] 2> 721034 T2939 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 722508 T2903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 722536 T2938 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> 722537 T2902 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> 722537 T2922 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> 722537 T2909 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> 722613 T2939 oasc.ZkController.register We are http://127.0.0.1:56562/u/il/collection1/ and leader is http://127.0.0.1:56562/u/il/collection1/
[junit4] 2> 722614 T2939 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56562/u/il
[junit4] 2> 722615 T2939 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 722615 T2939 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 722616 T2939 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 722620 T2939 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 722623 T2880 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 722624 T2880 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 722625 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 722790 T2880 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 722792 T2880 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50248
[junit4] 2> 722793 T2880 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 722794 T2880 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 722795 T2880 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374228631416
[junit4] 2> 722796 T2880 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374228631416/'
[junit4] 2> 722807 T2880 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374228631416/solr.xml
[junit4] 2> 722844 T2880 oasc.CoreContainer.<init> New CoreContainer 532553662
[junit4] 2> 722845 T2880 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374228631416/]
[junit4] 2> 722847 T2880 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 722847 T2880 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 722848 T2880 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 722849 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 722850 T2880 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 722851 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 722851 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 722852 T2880 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 722853 T2880 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 722854 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 722860 T2880 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 722862 T2880 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51997/solr
[junit4] 2> 722863 T2880 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 722864 T2880 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 722867 T2952 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@257c257c name:ZooKeeperConnection Watcher:127.0.0.1:51997 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 722867 T2880 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 722873 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 722880 T2880 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 722883 T2954 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9bd09bd name:ZooKeeperConnection Watcher:127.0.0.1:51997/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 722884 T2880 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 722903 T2880 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 723917 T2880 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50248_u%2Fil
[junit4] 2> 723922 T2880 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50248_u%2Fil
[junit4] 2> 723934 T2922 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 723934 T2909 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 723939 T2938 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 723941 T2954 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 723943 T2902 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 723943 T2902 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 723948 T2922 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 723955 T2938 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 723956 T2909 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 724300 T2903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 724303 T2955 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 724303 T2955 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 724327 T2903 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "shard_state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:56562/u/il",
[junit4] 2> "state":"active",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "node_name":"127.0.0.1:56562_u%2Fil",
[junit4] 2> "numShards":"2",
[junit4] 2> "shard_range":null,
[junit4] 2> "roles":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"collection1"}
[junit4] 2> 724329 T2955 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 724341 T2903 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "shard_state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:50248/u/il",
[junit4] 2> "state":"down",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "node_name":"127.0.0.1:50248_u%2Fil",
[junit4] 2> "numShards":"2",
[junit4] 2> "shard_range":null,
[junit4] 2> "roles":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard":null,
[junit4] 2> "core":"collection1"}
[junit4] 2> 724342 T2903 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 724343 T2903 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 724355 T2902 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> 724355 T2938 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> 724355 T2922 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> 724356 T2954 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> 724356 T2909 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> 725330 T2955 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 725331 T2955 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374228631416/collection1
[junit4] 2> 725331 T2955 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 725334 T2955 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 725334 T2955 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 725338 T2955 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374228631416/collection1/'
[junit4] 2> 725340 T2955 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374228631416/collection1/lib/README' to classloader
[junit4] 2> 725340 T2955 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374228631416/collection1/lib/classes/' to classloader
[junit4] 2> 725375 T2955 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 725412 T2955 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 725416 T2955 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 725424 T2955 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 725875 T2955 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 725876 T2955 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 725877 T2955 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 725883 T2955 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 725898 T2955 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 725936 T2955 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 725943 T2955 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 725951 T2955 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 725955 T2955 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 725956 T2955 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 725956 T2955 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 725961 T2955 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 725962 T2955 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 725963 T2955 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 725965 T2955 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374228631416/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty3/
[junit4] 2> 725966 T2955 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2bbb2bbb
[junit4] 2> 725969 T2955 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty3
[junit4] 2> 725970 T2955 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty3/index/
[junit4] 2> 725971 T2955 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 725973 T2955 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374228618310/jetty3/index
[junit4] 2> 725977 T2955 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8c008c0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4af44af4),segFN=segments_1,generation=1}
[junit4] 2> 725979 T2955 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 725988 T2955 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 725988 T2955 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 725989 T2955 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 725990 T2955 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 725991 T2955 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 725992 T2955 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 725993 T2955 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 725994 T2955 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 725994 T2955 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 725996 T2955 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 725999 T2955 oass.SolrIndexSearcher.<init> Opening Searcher@37183718 main
[junit4] 2> 726000 T2955 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 726001 T2955 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 726013 T2956 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@37183718 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 726022 T2955 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 726023 T2955 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50248/u/il collection:collection1 shard:shard1
[junit4] 2> 726025 T2955 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 726055 T2955 oasc.ZkController.register We are http://127.0.0.1:50248/u/il/collection1/ and leader is http://127.0.0.1:36660/u/il/collection1/
[junit4] 2> 726056 T2955 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50248/u/il
[junit4] 2> 726056 T2955 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 726057 T2955 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C2909 name=collection1 org.apache.solr.core.SolrCore@3e883e88 url=http://127.0.0.1:50248/u/il/collection1 node=127.0.0.1:50248_u%2Fil C2909_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:50248/u/il, state=down, node_name=127.0.0.1:50248_u%2Fil, core=collection1}
[junit4] 2> 726058 T2957 C2909 P50248 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 726058 T2957 C2909 P50248 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 726059 T2957 C2909 P50248 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 726059 T2955 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 726059 T2957 C2909 P50248 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 726062 T2880 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 726063 T2957 C2909 P50248 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 726063 T2880 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 726065 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 726076 T2916 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 726262 T2880 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 726264 T2880 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:38985
[junit4] 2> 726265 T2880 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 726266 T2880 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 726267 T2880 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374228634853
[junit4] 2> 726268 T2880 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374228634853/'
[junit4] 2> 726279 T2880 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374228634853/solr.xml
[junit4] 2> 726325 T2880 oasc.CoreContainer.<init> New CoreContainer 1407931371
[junit4] 2> 726326 T2880 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374228634853/]
[junit4] 2> 726327 T2880 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 726328 T2880 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 726329 T2880 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 726330 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 726331 T2880 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 726331 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 726332 T2880 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 726333 T2880 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 726334 T2880 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 726335 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 726341 T2880 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 726343 T2880 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51997/solr
[junit4] 2> 726344 T2880 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 726345 T2880 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 726348 T2969 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@365d365d name:ZooKeeperConnection Watcher:127.0.0.1:51997 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 726349 T2880 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 726356 T2880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 726366 T2880 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 726369 T2971 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@767a767a name:ZooKeeperConnection Watcher:127.0.0.1:51997/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 726370 T2880 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 726402 T2880 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 727416 T2903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 727420 T2880 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38985_u%2Fil
[junit4] 2> 727423 T2903 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "shard_state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:50248/u/il",
[junit4] 2> "state":"recovering",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "node_name":"127.0.0.1:50248_u%2Fil",
[junit4] 2> "numShards":"2",
[junit4] 2> "shard_range":null,
[junit4] 2> "roles":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"collection1"}
[junit4] 2> 727423 T2880 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38985_u%2Fil
[junit4] 2> 727436 T2938 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 727437 T2922 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 727437 T2909 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 727444 T2954 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 727444 T2971 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 727450 T2971 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 727450 T2938 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 727451 T2938 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 727473 T2922 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 727474 T2922 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 727475 T2954 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 727475 T2954 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeD
[...truncated too long message...]
> /solr/collections/onenodecollection/leader_elect/shard1/election (1)
[junit4] 1> /solr/collections/onenodecollection/leader_elect/shard1/election/90061446729826310-core_node1-n_0000000000 (0)
[junit4] 1> /solr/collections/onenodecollection/leaders (1)
[junit4] 1> /solr/collections/onenodecollection/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "base_url":"http://127.0.0.1:36660/u/il",
[junit4] 1> "node_name":"127.0.0.1:36660_u%2Fil",
[junit4] 1> "core":"onenodecollectioncore"}
[junit4] 1> /solr/aliases.json (0)
[junit4] 1> /solr/live_nodes (5)
[junit4] 1> /solr/live_nodes/127.0.0.1:50248_u%2Fil (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:54750_u%2Fil (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:38985_u%2Fil (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:56562_u%2Fil (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:36660_u%2Fil (0)
[junit4] 1> /solr/clusterstate.json (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "control_collection":{
[junit4] 1> "shards":{"shard1":{
[junit4] 1> "range":"80000000-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{"core_node1":{
[junit4] 1> "base_url":"http://127.0.0.1:54750/u/il",
[junit4] 1> "state":"active",
[junit4] 1> "node_name":"127.0.0.1:54750_u%2Fil",
[junit4] 1> "core":"collection1",
[junit4] 1> "leader":"true"}}}},
[junit4] 1> "router":"compositeId"},
[junit4] 1> "onenodecollection":{
[junit4] 1> "shards":{"shard1":{
[junit4] 1> "range":"80000000-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{"core_node1":{
[junit4] 1> "base_url":"http://127.0.0.1:36660/u/il",
[junit4] 1> "state":"active",
[junit4] 1> "node_name":"127.0.0.1:36660_u%2Fil",
[junit4] 1> "roles":"none",
[junit4] 1> "core":"onenodecollectioncore",
[junit4] 1> "leader":"true"}}}},
[junit4] 1> "router":"compositeId"},
[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> "base_url":"http://127.0.0.1:36660/u/il",
[junit4] 1> "state":"active",
[junit4] 1> "node_name":"127.0.0.1:36660_u%2Fil",
[junit4] 1> "core":"collection1",
[junit4] 1> "leader":"true"},
[junit4] 1> "core_node3":{
[junit4] 1> "base_url":"http://127.0.0.1:50248/u/il",
[junit4] 1> "state":"active",
[junit4] 1> "node_name":"127.0.0.1:50248_u%2Fil",
[junit4] 1> "core":"collection1"}}},
[junit4] 1> "shard2":{
[junit4] 1> "range":"0-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{
[junit4] 1> "core_node2":{
[junit4] 1> "base_url":"http://127.0.0.1:56562/u/il",
[junit4] 1> "state":"active",
[junit4] 1> "node_name":"127.0.0.1:56562_u%2Fil",
[junit4] 1> "core":"collection1",
[junit4] 1> "leader":"true"},
[junit4] 1> "core_node4":{
[junit4] 1> "base_url":"http://127.0.0.1:38985/u/il",
[junit4] 1> "state":"active",
[junit4] 1> "node_name":"127.0.0.1:38985_u%2Fil",
[junit4] 1> "core":"collection1"}}}},
[junit4] 1> "router":"compositeId"}}
[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=9F40A5078EB8081B -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=pt_PT -Dtests.timezone=Australia/Queensland -Dtests.file.encoding=US-ASCII
[junit4] ERROR 33.6s J0 | BasicDistributedZk2Test.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:56562/u/il/onenodecollectioncore returned non ok status:404, message:Can not find: /u/il/onenodecollectioncore/update
[junit4] > at __randomizedtesting.SeedInfo.seed([9F40A5078EB8081B:1EA62B1FF9E76827]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[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> 743111 T2880 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 33601 T2879 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4] 2> 743172 T2954 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 743173 T2954 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=pt_PT, timezone=Australia/Queensland
[junit4] 2> NOTE: Linux 3.2.0-49-generic x86/IBM Corporation 1.6.0 (32-bit)/cpus=8,threads=2,free=20359576,total=60675072
[junit4] 2> NOTE: All tests run in this JVM: [TestSolrQueryParser, HdfsChaosMonkeySafeLeaderTest, TestDynamicFieldResource, CoreAdminHandlerTest, TestSolrCoreProperties, MoreLikeThisHandlerTest, TestRemoteStreaming, LeaderElectionTest, TermsComponentTest, TestSweetSpotSimilarityFactory, TestSolrQueryParserDefaultOperatorResource, FastVectorHighlighterTest, TestPseudoReturnFields, TestCharFilters, ReturnFieldsTest, TestPHPSerializedResponseWriter, TestDocSet, OverseerTest, OverseerCollectionProcessorTest, TestPluginEnable, TestLFUCache, MinimalSchemaTest, PrimitiveFieldTypeTest, DocumentBuilderTest, HdfsBasicDistributedZkTest, TestSurroundQueryParser, TestQuerySenderListener, TestFunctionQuery, TestRealTimeGet, QueryParsingTest, TestSchemaSimilarityResource, TestConfig, UnloadDistributedZkTest, ZkControllerTest, SchemaVersionSpecificBehaviorTest, BinaryUpdateRequestHandlerTest, AnalysisAfterCoreReloadTest, TestReloadAndDeleteDocs, TestPhraseSuggestions, TestLMDirichletSimilarityFactory, TestStressVersions, DistributedQueryElevationComponentTest, TestPropInjectDefaults, UUIDFieldTest, StressHdfsTest, CSVRequestHandlerTest, TestReplicationHandler, SuggesterFSTTest, SynonymTokenizerTest, TestSchemaResource, SpellingQueryConverterTest, TestWriterPerf, DirectSolrConnectionTest, ClusterStateUpdateTest, HdfsDirectoryTest, TestSchemaNameResource, AlternateDirectoryTest, SliceStateUpdateTest, ZkCLITest, BasicFunctionalityTest, ResourceLoaderTest, AutoCommitTest, TestShardHandlerFactory, PolyFieldTest, SuggesterTest, TestSchemaVersionResource, TestSolrDeletionPolicy2, TestPerFieldSimilarity, TestFuzzyAnalyzedSuggestions, LukeRequestHandlerTest, ParsingFieldUpdateProcessorsTest, TestFieldResource, ExternalFileFieldSortTest, QueryEqualityTest, TestBadConfig, SolrIndexSplitterTest, SimpleFacetsTest, TestIBSimilarityFactory, BasicDistributedZkTest, BasicDistributedZk2Test]
[junit4] Completed on J0 in 33.92s, 1 test, 1 error <<< FAILURES!
[...truncated 502 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:395: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:388: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1250: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:893: There were test failures: 319 suites, 1345 tests, 1 error, 35 ignored (7 assumptions)
Total time: 52 minutes 14 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