You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/10/22 02:25:04 UTC
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4418 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4418/
1 tests failed.
REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch
Error Message:
Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:21948/collection1 Dead Guy:http://127.0.0.1:43715/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:43737/collection1], CloudJettyRunner [url=http://127.0.0.1:43737/collection1]]
Stack Trace:
java.lang.AssertionError: Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:21948/collection1 Dead Guy:http://127.0.0.1:43715/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:43737/collection1], CloudJettyRunner [url=http://127.0.0.1:43737/collection1]]
at __randomizedtesting.SeedInfo.seed([4171F94D3A7E0B61:C09777554D216B5D]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNotNull(Assert.java:526)
at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:216)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
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:724)
Build Log:
[...truncated 10160 lines...]
[junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4] 2> 595590 T1769 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 595595 T1769 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solrtest-SyncSliceTest-1382400100537
[junit4] 2> 595597 T1769 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 595597 T1770 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 595698 T1769 oasc.ZkTestServer.run start zk server on port:56375
[junit4] 2> 595699 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 595703 T1776 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@790e9e4e name:ZooKeeperConnection Watcher:127.0.0.1:56375 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 595703 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 595704 T1769 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 595716 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 595719 T1778 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@279de0bf name:ZooKeeperConnection Watcher:127.0.0.1:56375/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 595719 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 595719 T1769 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 595730 T1769 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 595733 T1769 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 595735 T1769 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 595744 T1769 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 595745 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 595758 T1769 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 595759 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 595863 T1769 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 595864 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 595867 T1769 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 595868 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 595878 T1769 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 595879 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 595881 T1769 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 595882 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 595885 T1769 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 595886 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 595888 T1769 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 595889 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 595892 T1769 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 595892 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 595895 T1769 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 595896 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 596215 T1769 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 596221 T1769 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:37567
[junit4] 2> 596222 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 596223 T1769 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 596223 T1769 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1382400100847
[junit4] 2> 596223 T1769 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1382400100847/'
[junit4] 2> 596268 T1769 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1382400100847/solr.xml
[junit4] 2> 596397 T1769 oasc.CoreContainer.<init> New CoreContainer 932208121
[junit4] 2> 596398 T1769 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1382400100847/]
[junit4] 2> 596400 T1769 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 596400 T1769 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 596401 T1769 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 596401 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 596402 T1769 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 596402 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 596403 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 596403 T1769 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 596404 T1769 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 596411 T1769 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 596412 T1769 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 596413 T1769 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56375/solr
[junit4] 2> 596413 T1769 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 596414 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 596417 T1789 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f7df5fa name:ZooKeeperConnection Watcher:127.0.0.1:56375 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 596418 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 596428 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 596431 T1791 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18cebd04 name:ZooKeeperConnection Watcher:127.0.0.1:56375/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 596431 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 596433 T1769 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 596442 T1769 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 596445 T1769 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 596452 T1769 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37567_
[junit4] 2> 596454 T1769 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37567_
[junit4] 2> 596457 T1769 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 596473 T1769 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 596481 T1769 oasc.Overseer.start Overseer (id=90596972989251587-127.0.0.1:37567_-n_0000000000) starting
[junit4] 2> 596491 T1769 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 596502 T1793 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 596503 T1769 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 596506 T1769 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 596508 T1769 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 596510 T1792 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 596517 T1794 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 596518 T1794 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 596519 T1794 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 598014 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 598015 T1792 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:37567",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37567_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 598015 T1792 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 598015 T1792 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 598032 T1791 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> 598522 T1794 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 598522 T1794 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1382400100847/collection1
[junit4] 2> 598522 T1794 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 598523 T1794 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 598523 T1794 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 598524 T1794 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1382400100847/collection1/'
[junit4] 2> 598526 T1794 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-controljetty-1382400100847/collection1/lib/classes/' to classloader
[junit4] 2> 598527 T1794 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-controljetty-1382400100847/collection1/lib/README' to classloader
[junit4] 2> 598584 T1794 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 598636 T1794 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 598737 T1794 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 598745 T1794 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 599200 T1794 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 599210 T1794 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 599213 T1794 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 599224 T1794 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 599228 T1794 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 599232 T1794 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 599233 T1794 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 599233 T1794 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 599233 T1794 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 599234 T1794 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 599234 T1794 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 599235 T1794 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 599235 T1794 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1382400100847/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1382400100537/control/data/
[junit4] 2> 599235 T1794 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@63c53898
[junit4] 2> 599236 T1794 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1382400100537/control/data
[junit4] 2> 599236 T1794 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1382400100537/control/data/index/
[junit4] 2> 599236 T1794 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1382400100537/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 599237 T1794 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1382400100537/control/data/index
[junit4] 2> 599237 T1794 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=11, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 599238 T1794 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@434d4f2b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@68508e3c),segFN=segments_1,generation=1}
[junit4] 2> 599238 T1794 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 599241 T1794 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 599242 T1794 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 599242 T1794 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 599242 T1794 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 599243 T1794 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 599243 T1794 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 599243 T1794 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 599244 T1794 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 599244 T1794 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 599244 T1794 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 599245 T1794 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 599245 T1794 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 599245 T1794 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 599246 T1794 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 599246 T1794 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 599257 T1794 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 599262 T1794 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 599262 T1794 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 599263 T1794 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=14, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 599263 T1794 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@434d4f2b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@68508e3c),segFN=segments_1,generation=1}
[junit4] 2> 599264 T1794 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 599264 T1794 oass.SolrIndexSearcher.<init> Opening Searcher@6554419a main
[junit4] 2> 599267 T1795 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6554419a main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 599268 T1794 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 599269 T1794 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37567 collection:control_collection shard:shard1
[junit4] 2> 599270 T1794 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 599409 T1794 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 599475 T1794 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 599475 T1794 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 599475 T1794 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37567/collection1/
[junit4] 2> 599475 T1794 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 599476 T1794 oasc.SyncStrategy.syncToMe http://127.0.0.1:37567/collection1/ has no replicas
[junit4] 2> 599476 T1794 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37567/collection1/ shard1
[junit4] 2> 599476 T1794 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 599556 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 599608 T1791 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> 599658 T1794 oasc.ZkController.register We are http://127.0.0.1:37567/collection1/ and leader is http://127.0.0.1:37567/collection1/
[junit4] 2> 599658 T1794 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37567
[junit4] 2> 599658 T1794 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 599658 T1794 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 599659 T1794 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 599660 T1794 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 599661 T1769 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 599662 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 599664 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 599665 T1798 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59fe35a8 name:ZooKeeperConnection Watcher:127.0.0.1:56375/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 599666 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 599666 T1769 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 599668 T1769 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 599853 T1769 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 599856 T1769 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:43715
[junit4] 2> 599856 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 599857 T1769 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 599857 T1769 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1382400104610
[junit4] 2> 599857 T1769 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1382400104610/'
[junit4] 2> 599884 T1769 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1382400104610/solr.xml
[junit4] 2> 599950 T1769 oasc.CoreContainer.<init> New CoreContainer 1935610662
[junit4] 2> 599951 T1769 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1382400104610/]
[junit4] 2> 599953 T1769 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 599953 T1769 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 599953 T1769 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 599954 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 599954 T1769 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 599954 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 599955 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 599955 T1769 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 599955 T1769 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 599960 T1769 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 599961 T1769 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 599961 T1769 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56375/solr
[junit4] 2> 599961 T1769 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 599962 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 599969 T1809 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@73cb9f4b name:ZooKeeperConnection Watcher:127.0.0.1:56375 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 599970 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 599976 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 599984 T1811 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f55808d name:ZooKeeperConnection Watcher:127.0.0.1:56375/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 599985 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 599988 T1769 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 600991 T1769 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43715_
[junit4] 2> 601018 T1769 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43715_
[junit4] 2> 601021 T1791 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 601021 T1811 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 601021 T1798 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 601034 T1812 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 601034 T1812 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 601036 T1812 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 601112 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 601113 T1792 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:37567",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37567_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 601115 T1792 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:43715",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:43715_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 601116 T1792 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 601116 T1792 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 601132 T1798 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> 601132 T1811 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> 601132 T1791 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> 602037 T1812 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 602037 T1812 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1382400104610/collection1
[junit4] 2> 602037 T1812 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 602038 T1812 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 602038 T1812 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 602039 T1812 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1382400104610/collection1/'
[junit4] 2> 602040 T1812 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty1-1382400104610/collection1/lib/README' to classloader
[junit4] 2> 602041 T1812 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty1-1382400104610/collection1/lib/classes/' to classloader
[junit4] 2> 602086 T1812 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 602130 T1812 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 602231 T1812 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 602239 T1812 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 602686 T1812 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 602695 T1812 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 602698 T1812 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 602707 T1812 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 602711 T1812 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 602714 T1812 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 602715 T1812 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 602716 T1812 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 602716 T1812 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 602717 T1812 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 602717 T1812 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 602717 T1812 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 602717 T1812 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1382400104610/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty1/
[junit4] 2> 602718 T1812 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@63c53898
[junit4] 2> 602718 T1812 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty1
[junit4] 2> 602719 T1812 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty1/index/
[junit4] 2> 602719 T1812 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 602719 T1812 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty1/index
[junit4] 2> 602720 T1812 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=11, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 602720 T1812 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6e9a09b9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@65ebc6b0),segFN=segments_1,generation=1}
[junit4] 2> 602720 T1812 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 602724 T1812 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 602725 T1812 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 602725 T1812 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 602725 T1812 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 602725 T1812 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 602726 T1812 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 602726 T1812 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 602726 T1812 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 602726 T1812 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 602727 T1812 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 602727 T1812 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 602728 T1812 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 602728 T1812 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 602728 T1812 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 602729 T1812 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 602739 T1812 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 602743 T1812 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 602744 T1812 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 602744 T1812 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=14, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 602745 T1812 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6e9a09b9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@65ebc6b0),segFN=segments_1,generation=1}
[junit4] 2> 602745 T1812 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 602745 T1812 oass.SolrIndexSearcher.<init> Opening Searcher@3823bdae main
[junit4] 2> 602749 T1813 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3823bdae main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 602751 T1812 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 602751 T1812 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43715 collection:collection1 shard:shard1
[junit4] 2> 602753 T1812 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 602772 T1812 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 602783 T1812 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 602783 T1812 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 602783 T1812 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:43715/collection1/
[junit4] 2> 602783 T1812 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 602784 T1812 oasc.SyncStrategy.syncToMe http://127.0.0.1:43715/collection1/ has no replicas
[junit4] 2> 602784 T1812 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:43715/collection1/ shard1
[junit4] 2> 602784 T1812 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 604139 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 604168 T1798 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> 604168 T1811 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> 604168 T1791 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> 604217 T1812 oasc.ZkController.register We are http://127.0.0.1:43715/collection1/ and leader is http://127.0.0.1:43715/collection1/
[junit4] 2> 604217 T1812 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43715
[junit4] 2> 604217 T1812 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 604217 T1812 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 604218 T1812 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 604285 T1812 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 604286 T1769 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 604286 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 604469 T1769 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 604472 T1769 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:43737
[junit4] 2> 604472 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 604473 T1769 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 604473 T1769 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1382400109229
[junit4] 2> 604473 T1769 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1382400109229/'
[junit4] 2> 604500 T1769 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1382400109229/solr.xml
[junit4] 2> 604562 T1769 oasc.CoreContainer.<init> New CoreContainer 1437293283
[junit4] 2> 604563 T1769 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1382400109229/]
[junit4] 2> 604564 T1769 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 604564 T1769 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 604565 T1769 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 604565 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 604565 T1769 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 604565 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 604566 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 604566 T1769 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 604566 T1769 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 604571 T1769 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 604571 T1769 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 604572 T1769 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56375/solr
[junit4] 2> 604572 T1769 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 604573 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 604579 T1825 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18510141 name:ZooKeeperConnection Watcher:127.0.0.1:56375 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 604579 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 604582 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 604594 T1827 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ec0a3fc name:ZooKeeperConnection Watcher:127.0.0.1:56375/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 604594 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 604597 T1769 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 605600 T1769 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43737_
[junit4] 2> 605607 T1769 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43737_
[junit4] 2> 605609 T1798 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 605609 T1827 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 605609 T1811 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 605609 T1791 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 605628 T1828 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 605629 T1828 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 605631 T1828 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 605787 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 605788 T1792 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:43715",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:43715_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 605791 T1792 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:43737",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:43737_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 605791 T1792 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 605791 T1792 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 605810 T1791 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> 605810 T1798 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> 605810 T1811 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> 605810 T1827 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> 606633 T1828 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 606633 T1828 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1382400109229/collection1
[junit4] 2> 606633 T1828 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 606634 T1828 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 606634 T1828 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 606635 T1828 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1382400109229/collection1/'
[junit4] 2> 606636 T1828 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty2-1382400109229/collection1/lib/classes/' to classloader
[junit4] 2> 606637 T1828 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty2-1382400109229/collection1/lib/README' to classloader
[junit4] 2> 606682 T1828 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 606726 T1828 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 606827 T1828 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 606835 T1828 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 607286 T1828 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 607295 T1828 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 607298 T1828 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 607309 T1828 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 607313 T1828 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 607317 T1828 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 607318 T1828 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 607319 T1828 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 607319 T1828 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 607319 T1828 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 607320 T1828 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 607320 T1828 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 607320 T1828 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1382400109229/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty2/
[junit4] 2> 607321 T1828 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@63c53898
[junit4] 2> 607322 T1828 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty2
[junit4] 2> 607322 T1828 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty2/index/
[junit4] 2> 607322 T1828 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 607322 T1828 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty2/index
[junit4] 2> 607323 T1828 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=11, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 607323 T1828 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@3250f674 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5f27c4dd),segFN=segments_1,generation=1}
[junit4] 2> 607324 T1828 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 607327 T1828 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 607328 T1828 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 607328 T1828 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 607328 T1828 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 607329 T1828 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 607329 T1828 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 607329 T1828 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 607330 T1828 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 607330 T1828 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 607330 T1828 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 607331 T1828 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 607331 T1828 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 607331 T1828 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 607332 T1828 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 607332 T1828 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 607343 T1828 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 607347 T1828 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 607347 T1828 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 607348 T1828 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=14, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 607349 T1828 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@3250f674 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5f27c4dd),segFN=segments_1,generation=1}
[junit4] 2> 607349 T1828 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 607349 T1828 oass.SolrIndexSearcher.<init> Opening Searcher@34e7b657 main
[junit4] 2> 607353 T1829 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@34e7b657 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 607354 T1828 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 607355 T1828 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43737 collection:collection1 shard:shard1
[junit4] 2> 607358 T1828 oasc.ZkController.register We are http://127.0.0.1:43737/collection1/ and leader is http://127.0.0.1:43715/collection1/
[junit4] 2> 607358 T1828 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43737
[junit4] 2> 607358 T1828 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 607358 T1828 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C338 name=collection1 org.apache.solr.core.SolrCore@22d24f6f url=http://127.0.0.1:43737/collection1 node=127.0.0.1:43737_ C338_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:43737, core=collection1, node_name=127.0.0.1:43737_}
[junit4] 2> 607359 T1830 C338 P43737 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 607359 T1828 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 607360 T1830 C338 P43737 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 607360 T1830 C338 P43737 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 607360 T1830 C338 P43737 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 607360 T1769 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 607361 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 607364 T1801 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 607549 T1769 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 607551 T1769 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:21948
[junit4] 2> 607552 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 607552 T1769 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 607553 T1769 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.SyncSliceTest-jetty3-1382400112303
[junit4] 2> 607553 T1769 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty3-1382400112303/'
[junit4] 2> 607581 T1769 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1382400112303/solr.xml
[junit4] 2> 607643 T1769 oasc.CoreContainer.<init> New CoreContainer 1846391394
[junit4] 2> 607644 T1769 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.SyncSliceTest-jetty3-1382400112303/]
[junit4] 2> 607645 T1769 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 607645 T1769 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 607646 T1769 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 607646 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 607646 T1769 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 607647 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 607647 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 607647 T1769 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 607648 T1769 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 607652 T1769 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 607652 T1769 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 607653 T1769 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56375/solr
[junit4] 2> 607653 T1769 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 607654 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 607656 T1842 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14ac3f0e name:ZooKeeperConnection Watcher:127.0.0.1:56375 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 607657 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 607660 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 607669 T1844 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2cd756b3 name:ZooKeeperConnection Watcher:127.0.0.1:56375/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 607670 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 607678 T1769 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 608681 T1769 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:21948_
[junit4] 2> 608683 T1769 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:21948_
[junit4] 2> 608685 T1791 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 608685 T1827 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 608685 T1844 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 608685 T1798 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 608685 T1811 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 608701 T1845 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 608702 T1845 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 608703 T1845 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 608816 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 608817 T1792 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "base_url":"http://127.0.0.1:43737",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:43737_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 608820 T1792 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:21948",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:21948_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node3"}
[junit4] 2> 608820 T1792 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 608820 T1792 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 608832 T1791 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> 608832 T1827 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> 608832 T1844 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> 608832 T1798 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> 608832 T1811 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> 609366 T1801 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4] 2> 609366 T1801 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=core_node2&state=recovering&nodeName=127.0.0.1:43737_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2002
[junit4] 2> 609704 T1845 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 609704 T1845 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.SyncSliceTest-jetty3-1382400112303/collection1
[junit4] 2> 609704 T1845 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 609705 T1845 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 609705 T1845 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 609706 T1845 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty3-1382400112303/collection1/'
[junit4] 2> 609707 T1845 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty3-1382400112303/collection1/lib/README' to classloader
[junit4] 2> 609707 T1845 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty3-1382400112303/collection1/lib/classes/' to classloader
[junit4] 2> 609753 T1845 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 609797 T1845 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 609899 T1845 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 609907 T1845 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 610549 T1845 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 610563 T1845 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 610568 T1845 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 610581 T1845 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 610586 T1845 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 610590 T1845 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 610591 T1845 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 610592 T1845 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 610593 T1845 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 610593 T1845 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 610594 T1845 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 610594 T1845 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 610594 T1845 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.SyncSliceTest-jetty3-1382400112303/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty3/
[junit4] 2> 610595 T1845 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@63c53898
[junit4] 2> 610596 T1845 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty3
[junit4] 2> 610596 T1845 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty3/index/
[junit4] 2> 610596 T1845 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 610597 T1845 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1382400100537/jetty3/index
[junit4] 2> 610597 T1845 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=11, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 610598 T1845 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@10eb58af lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8f58a2c),segFN=segments_1,generation=1}
[junit4] 2> 610599 T1845 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 610604 T1845 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 610605 T1845 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 610605 T1845 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 610605 T1845 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 610606 T1845 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 610606 T1845 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 610607 T1845 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 610607 T1845 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 610607 T1845 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 610608 T1845 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 610609 T1845 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 610609 T1845 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 610610 T1845 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 610610 T1845 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 610611 T1845 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 610630 T1845 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 610636 T1845 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 610636 T1845 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 610637 T1845 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=14, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 610638 T1845 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@10eb58af lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8f58a2c),segFN=segments_1,generation=1}
[junit4] 2> 610638 T1845 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 610638 T1845 oass.SolrIndexSearcher.<init> Opening Searcher@73c500e1 main
[junit4] 2> 610644 T1846 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@73c500e1 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 610646 T1845 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 610647 T1845 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:21948 collection:collection1 shard:shard1
[junit4] 2> 610651 T1845 oasc.ZkController.register We are http://127.0.0.1:21948/collection1/ and leader is http://127.0.0.1:43715/collection1/
[junit4] 2> 610651 T1845 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:21948
[junit4] 2> 610651 T1845 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 610651 T1845 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C339 name=collection1 org.apache.solr.core.SolrCore@22e953a1 url=http://127.0.0.1:21948/collection1 node=127.0.0.1:21948_ C339_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:21948, core=collection1, node_name=127.0.0.1:21948_}
[junit4] 2> 610652 T1847 C339 P21948 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 610652 T1845 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 610652 T1847 C339 P21948 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 610653 T1847 C339 P21948 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 610653 T1847 C339 P21948 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 610653 T1769 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 610654 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 610667 T1802 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 610957 T1769 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 610960 T1769 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:36591
[junit4] 2> 610960 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 610961 T1769 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 610961 T1769 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty4-1382400115596
[junit4] 2> 610962 T1769 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty4-1382400115596/'
[junit4] 2> 611004 T1769 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty4-1382400115596/solr.xml
[junit4] 2> 611097 T1769 oasc.CoreContainer.<init> New CoreContainer 196456763
[junit4] 2> 611098 T1769 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty4-1382400115596/]
[junit4] 2> 611100 T1769 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 611100 T1769 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 611101 T1769 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 611101 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 611102 T1769 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 611102 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 611102 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 611103 T1769 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 611103 T1769 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 611110 T1769 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 611111 T1769 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 611111 T1769 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56375/solr
[junit4] 2> 611112 T1769 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 611113 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 611115 T1859 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a1cf182 name:ZooKeeperConnection Watcher:127.0.0.1:56375 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 611116 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 611119 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 611121 T1861 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@764f920a name:ZooKeeperConnection Watcher:127.0.0.1:56375/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 611121 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 611125 T1769 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C340 name=collection1 org.apache.solr.core.SolrCore@22d24f6f url=http://127.0.0.1:43737/collection1 node=127.0.0.1:43737_ C340_STATE=coll:collection1 core:collection1 props:{state=recovering, base_url=http://127.0.0.1:43737, core=collection1, node_name=127.
[...truncated too long message...]
"base_url":"http://127.0.0.1:36591",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:36591_"}}}},
[junit4] 1> "maxShardsPerNode":"1",
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "replicationFactor":"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> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:37567",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:37567_",
[junit4] 1> "leader":"true"}}}},
[junit4] 1> "maxShardsPerNode":"1",
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "replicationFactor":"1"}}
[junit4] 1> /solr/aliases.json (0)
[junit4] 1> /solr/live_nodes (5)
[junit4] 1> /solr/live_nodes/127.0.0.1:36591_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:43715_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:37567_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:21948_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:43737_ (0)
[junit4] 1> /solr/overseer (3)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1> /solr/overseer/queue (0)
[junit4] 1> /solr/overseer/queue-work (0)
[junit4] 1> /solr/overseer/collection-queue-work (0)
[junit4] 1> /solr/collections (2)
[junit4] 1> /solr/collections/collection1 (3)
[junit4] 1> DATA:
[junit4] 1> {"configName":"conf1"}
[junit4] 1> /solr/collections/collection1/shards (0)
[junit4] 1> /solr/collections/collection1/leader_elect (1)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election (4)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90596972989251598-core_node1-n_0000000005 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90596972989251592-core_node2-n_0000000004 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90596972989251594-core_node3-n_0000000002 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90596972989251596-core_node4-n_0000000003 (0)
[junit4] 1> /solr/collections/collection1/leaders (1)
[junit4] 1> /solr/collections/collection1/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:21948_",
[junit4] 1> "base_url":"http://127.0.0.1:21948"}
[junit4] 1> /solr/collections/control_collection (3)
[junit4] 1> DATA:
[junit4] 1> {"configName":"conf1"}
[junit4] 1> /solr/collections/control_collection/shards (0)
[junit4] 1> /solr/collections/control_collection/leader_elect (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election/90596972989251587-core_node1-n_0000000000 (0)
[junit4] 1> /solr/collections/control_collection/leaders (1)
[junit4] 1> /solr/collections/control_collection/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:37567_",
[junit4] 1> "base_url":"http://127.0.0.1:37567"}
[junit4] 1> /solr/overseer_elect (2)
[junit4] 1> /solr/overseer_elect/election (5)
[junit4] 1> /solr/overseer_elect/election/90596972989251596-127.0.0.1:36591_-n_0000000004 (0)
[junit4] 1> /solr/overseer_elect/election/90596972989251587-127.0.0.1:37567_-n_0000000000 (0)
[junit4] 1> /solr/overseer_elect/election/90596972989251594-127.0.0.1:21948_-n_0000000003 (0)
[junit4] 1> /solr/overseer_elect/election/90596972989251598-127.0.0.1:43715_-n_0000000005 (0)
[junit4] 1> /solr/overseer_elect/election/90596972989251592-127.0.0.1:43737_-n_0000000002 (0)
[junit4] 1> /solr/overseer_elect/leader (0)
[junit4] 1> DATA:
[junit4] 1> {"id":"90596972989251587-127.0.0.1:37567_-n_0000000000"}
[junit4] 1> /zookeeper (1)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SyncSliceTest -Dtests.method=testDistribSearch -Dtests.seed=4171F94D3A7E0B61 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sv_SE -Dtests.timezone=Africa/Niamey -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 153s J0 | SyncSliceTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:21948/collection1 Dead Guy:http://127.0.0.1:43715/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:43737/collection1], CloudJettyRunner [url=http://127.0.0.1:43737/collection1]]
[junit4] > at __randomizedtesting.SeedInfo.seed([4171F94D3A7E0B61:C09777554D216B5D]:0)
[junit4] > at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:216)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] 2> 748887 T1769 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 153302 T1768 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Lucene46: {range_facet_l=PostingsFormat(name=Lucene41VarGapFixedInterval), text=PostingsFormat(name=SimpleText), _version_=PostingsFormat(name=MockSep), rnd_b=FST41, intDefault=PostingsFormat(name=MockSep), timestamp=PostingsFormat(name=Lucene41VarGapFixedInterval), id=FST41, a_t=PostingsFormat(name=Lucene41VarGapFixedInterval), range_facet_sl=FST41, range_facet_si=PostingsFormat(name=Lucene41VarGapFixedInterval), other_tl1=PostingsFormat(name=MockSep), multiDefault=PostingsFormat(name=Lucene41VarGapFixedInterval), a_si=PostingsFormat(name=MockSep)}, docValues:{timestamp=DocValuesFormat(name=Disk)}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=sv_SE, timezone=Africa/Niamey
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=348977728,total=448790528
[junit4] 2> NOTE: All tests run in this JVM: [TestCharFilters, TestPerFieldSimilarity, WordBreakSolrSpellCheckerTest, TestSort, TestStressVersions, SliceStateUpdateTest, FieldMutatingUpdateProcessorTest, UnloadDistributedZkTest, PreAnalyzedUpdateProcessorTest, LeaderElectionTest, DocValuesMissingTest, HdfsLockFactoryTest, SearchHandlerTest, HdfsBasicDistributedZk2Test, OverseerCollectionProcessorTest, CircularListTest, ZkCLITest, QueryResultKeyTest, TestJoin, TestLRUCache, TestRemoteStreaming, HdfsChaosMonkeySafeLeaderTest, TestLFUCache, StatelessScriptUpdateProcessorFactoryTest, SolrIndexSplitterTest, TermVectorComponentTest, TestBadConfig, HdfsBasicDistributedZkTest, TestSearchPerf, TestSuggestSpellingConverter, TestReversedWildcardFilterFactory, DistributedSpellCheckComponentTest, TestSolrXMLSerializer, ClusterStateUpdateTest, TestPostingsSolrHighlighter, SolrXmlInZkTest, ReturnFieldsTest, TestDocSet, TestSystemIdResolver, EchoParamsTest, ScriptEngineTest, SimpleFacetsTest, QueryElevationComponentTest, ZkControllerTest, TestCoreContainer, DocValuesTest, ResourceLoaderTest, SystemInfoHandlerTest, TestFaceting, OverseerTest, SuggesterTest, MBeansHandlerTest, TestMergePolicyConfig, LukeRequestHandlerTest, DOMUtilTest, TestLuceneMatchVersion, TestExtendedDismaxParser, AutoCommitTest, TestPseudoReturnFields, LegacyHTMLStripCharFilterTest, SOLR749Test, SolrTestCaseJ4Test, ParsingFieldUpdateProcessorsTest, PeerSyncTest, TestGroupingSearch, TestPHPSerializedResponseWriter, TestQueryUtils, ExternalFileFieldSortTest, TestShardHandlerFactory, SampleTest, SyncSliceTest]
[junit4] Completed on J0 in 153.58s, 1 test, 1 failure <<< FAILURES!
[...truncated 676 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:422: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:402: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:483: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1259: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:902: There were test failures: 326 suites, 1449 tests, 1 failure, 35 ignored (6 assumptions)
Total time: 60 minutes 38 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure