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/09/14 04:58:25 UTC
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4316 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4316/
1 tests failed.
REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch
Error Message:
expected:<5> but was:<4>
Stack Trace:
java.lang.AssertionError: expected:<5> but was:<4>
at __randomizedtesting.SeedInfo.seed([DBC0E5D5C9B98656:5A266BCDBEE6E66A]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:175)
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 9922 lines...]
[junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4] 2> 1254524 T2735 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 1254529 T2735 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-1379126703785
[junit4] 2> 1254530 T2735 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1254530 T2736 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1254631 T2735 oasc.ZkTestServer.run start zk server on port:34608
[junit4] 2> 1254632 T2735 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1254637 T2742 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70bfec04 name:ZooKeeperConnection Watcher:127.0.0.1:34608 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1254637 T2735 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1254638 T2735 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1254642 T2735 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1254651 T2744 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f8ab217 name:ZooKeeperConnection Watcher:127.0.0.1:34608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1254651 T2735 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1254652 T2735 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1254654 T2735 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1254656 T2735 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1254658 T2735 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1254660 T2735 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> 1254660 T2735 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1254665 T2735 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> 1254665 T2735 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1254768 T2735 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> 1254769 T2735 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1254772 T2735 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> 1254772 T2735 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1254784 T2735 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> 1254785 T2735 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1254801 T2735 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> 1254802 T2735 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1254805 T2735 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> 1254805 T2735 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1254808 T2735 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> 1254808 T2735 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1254816 T2735 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> 1254816 T2735 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1254819 T2735 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> 1254819 T2735 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1255674 T2735 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1255682 T2735 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:34627
[junit4] 2> 1255684 T2735 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1255685 T2735 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1255686 T2735 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.SyncSliceTest-controljetty-1379126704084
[junit4] 2> 1255686 T2735 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-controljetty-1379126704084/'
[junit4] 2> 1255905 T2735 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-controljetty-1379126704084/solr.xml
[junit4] 2> 1256253 T2735 oasc.CoreContainer.<init> New CoreContainer 1820406546
[junit4] 2> 1256255 T2735 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.SyncSliceTest-controljetty-1379126704084/]
[junit4] 2> 1256261 T2735 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1256262 T2735 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1256262 T2735 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1256263 T2735 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1256264 T2735 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1256264 T2735 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1256265 T2735 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1256266 T2735 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1256266 T2735 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1256267 T2735 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1256359 T2735 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1256360 T2735 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1256361 T2735 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:34608/solr
[junit4] 2> 1256362 T2735 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1256363 T2735 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1256366 T2755 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5baefbcc name:ZooKeeperConnection Watcher:127.0.0.1:34608 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1256369 T2735 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1256373 T2735 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1256390 T2735 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1256399 T2757 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2817cce4 name:ZooKeeperConnection Watcher:127.0.0.1:34608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1256401 T2735 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1256408 T2735 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1256434 T2735 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1256449 T2735 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1256457 T2735 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34627_
[junit4] 2> 1256463 T2735 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34627_
[junit4] 2> 1256486 T2735 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1256522 T2735 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1256532 T2735 oasc.Overseer.start Overseer (id=90382447659712515-127.0.0.1:34627_-n_0000000000) starting
[junit4] 2> 1256555 T2735 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1256564 T2759 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1256565 T2735 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1256579 T2735 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1256582 T2735 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1256584 T2758 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1256610 T2760 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1256610 T2760 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1256620 T2760 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1258094 T2758 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1258096 T2758 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:34627_",
[junit4] 2> "base_url":"http://127.0.0.1:34627"}
[junit4] 2> 1258096 T2758 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1258096 T2758 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1258139 T2757 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> 1258625 T2760 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1258625 T2760 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.SyncSliceTest-controljetty-1379126704084/collection1
[junit4] 2> 1258626 T2760 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1258627 T2760 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1258627 T2760 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1258628 T2760 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-controljetty-1379126704084/collection1/'
[junit4] 2> 1258633 T2760 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-1379126704084/collection1/lib/README' to classloader
[junit4] 2> 1258635 T2760 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-1379126704084/collection1/lib/classes/' to classloader
[junit4] 2> 1258801 T2760 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1258913 T2760 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1259015 T2760 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1259025 T2760 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 1259541 T2760 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1259550 T2760 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1259553 T2760 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1259565 T2760 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1259569 T2760 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1259574 T2760 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1259575 T2760 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1259575 T2760 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1259575 T2760 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1259576 T2760 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1259576 T2760 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1259576 T2760 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1259577 T2760 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.SyncSliceTest-controljetty-1379126704084/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1379126703784/control/data/
[junit4] 2> 1259577 T2760 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@65716a7e
[junit4] 2> 1259578 T2760 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1379126703784/control/data
[junit4] 2> 1259578 T2760 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1379126703784/control/data/index/
[junit4] 2> 1259578 T2760 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1379126703784/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1259578 T2760 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1379126703784/control/data/index
[junit4] 2> 1259579 T2760 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=639627132, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1259580 T2760 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2eec7e75 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1485817f),segFN=segments_1,generation=1}
[junit4] 2> 1259580 T2760 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1259583 T2760 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1259583 T2760 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1259584 T2760 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1259584 T2760 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1259584 T2760 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1259584 T2760 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1259585 T2760 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1259585 T2760 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1259585 T2760 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1259586 T2760 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1259586 T2760 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1259587 T2760 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1259587 T2760 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1259587 T2760 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1259588 T2760 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1259599 T2760 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1259604 T2760 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1259604 T2760 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1259605 T2760 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=38, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7331740695332857]
[junit4] 2> 1259605 T2760 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2eec7e75 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1485817f),segFN=segments_1,generation=1}
[junit4] 2> 1259605 T2760 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1259606 T2760 oass.SolrIndexSearcher.<init> Opening Searcher@3beb49b4 main
[junit4] 2> 1259609 T2761 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3beb49b4 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1259609 T2760 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1259610 T2760 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:34627 collection:control_collection shard:shard1
[junit4] 2> 1259610 T2760 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1259617 T2760 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1259635 T2760 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1259644 T2760 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1259644 T2760 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1259644 T2760 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:34627/collection1/
[junit4] 2> 1259644 T2760 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1259645 T2760 oasc.SyncStrategy.syncToMe http://127.0.0.1:34627/collection1/ has no replicas
[junit4] 2> 1259645 T2760 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:34627/collection1/ shard1
[junit4] 2> 1259645 T2760 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1259647 T2758 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1259668 T2757 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> 1259710 T2760 oasc.ZkController.register We are http://127.0.0.1:34627/collection1/ and leader is http://127.0.0.1:34627/collection1/
[junit4] 2> 1259710 T2760 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34627
[junit4] 2> 1259710 T2760 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1259710 T2760 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1259710 T2760 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1259712 T2760 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1259713 T2735 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1259713 T2735 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1259714 T2735 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1259720 T2735 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 1259721 T2735 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1259723 T2764 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5feda917 name:ZooKeeperConnection Watcher:127.0.0.1:34608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1259723 T2735 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1259724 T2735 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1259726 T2735 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 1259922 T2735 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1259925 T2735 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:34631
[junit4] 2> 1259926 T2735 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1259926 T2735 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1259927 T2735 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-1379126708981
[junit4] 2> 1259927 T2735 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-1379126708981/'
[junit4] 2> 1259955 T2735 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-1379126708981/solr.xml
[junit4] 2> 1260044 T2735 oasc.CoreContainer.<init> New CoreContainer 149930775
[junit4] 2> 1260045 T2735 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-1379126708981/]
[junit4] 2> 1260046 T2735 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1260047 T2735 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1260047 T2735 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1260048 T2735 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1260048 T2735 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1260049 T2735 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1260049 T2735 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1260050 T2735 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1260050 T2735 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1260051 T2735 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1260066 T2735 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1260067 T2735 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1260067 T2735 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:34608/solr
[junit4] 2> 1260068 T2735 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1260069 T2735 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1260074 T2775 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@468177aa name:ZooKeeperConnection Watcher:127.0.0.1:34608 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1260074 T2735 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1260088 T2735 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1260099 T2735 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1260101 T2777 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2991ff0d name:ZooKeeperConnection Watcher:127.0.0.1:34608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1260101 T2735 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1260110 T2735 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1261113 T2735 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34631_
[junit4] 2> 1261119 T2735 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34631_
[junit4] 2> 1261125 T2757 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1261125 T2777 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1261126 T2757 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1261125 T2764 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1261141 T2778 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1261142 T2778 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1261144 T2778 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1261174 T2758 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1261175 T2758 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"active",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:34627_",
[junit4] 2> "base_url":"http://127.0.0.1:34627"}
[junit4] 2> 1261192 T2758 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:34631_",
[junit4] 2> "base_url":"http://127.0.0.1:34631"}
[junit4] 2> 1261192 T2758 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1261193 T2758 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1261205 T2777 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> 1261205 T2764 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> 1261205 T2757 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> 1262145 T2778 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1262145 T2778 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-1379126708981/collection1
[junit4] 2> 1262145 T2778 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1262146 T2778 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1262147 T2778 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1262147 T2778 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-1379126708981/collection1/'
[junit4] 2> 1262149 T2778 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-1379126708981/collection1/lib/classes/' to classloader
[junit4] 2> 1262151 T2778 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-1379126708981/collection1/lib/README' to classloader
[junit4] 2> 1262217 T2778 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1262282 T2778 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1262383 T2778 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1262395 T2778 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 1263068 T2778 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1263081 T2778 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1263086 T2778 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1263101 T2778 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1263106 T2778 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1263110 T2778 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1263111 T2778 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1263113 T2778 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1263113 T2778 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1263114 T2778 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1263114 T2778 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1263115 T2778 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1263115 T2778 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-1379126708981/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty1/
[junit4] 2> 1263116 T2778 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@65716a7e
[junit4] 2> 1263117 T2778 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty1
[junit4] 2> 1263117 T2778 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty1/index/
[junit4] 2> 1263117 T2778 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1263118 T2778 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty1/index
[junit4] 2> 1263119 T2778 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=639627132, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1263120 T2778 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@78b4ca30 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2c9c6fcd),segFN=segments_1,generation=1}
[junit4] 2> 1263120 T2778 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1263125 T2778 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1263125 T2778 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1263126 T2778 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1263126 T2778 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1263127 T2778 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1263127 T2778 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1263127 T2778 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1263128 T2778 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1263128 T2778 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1263129 T2778 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1263130 T2778 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1263130 T2778 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1263130 T2778 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1263131 T2778 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1263132 T2778 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1263148 T2778 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1263154 T2778 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1263154 T2778 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1263155 T2778 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=38, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7331740695332857]
[junit4] 2> 1263156 T2778 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@78b4ca30 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2c9c6fcd),segFN=segments_1,generation=1}
[junit4] 2> 1263156 T2778 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1263157 T2778 oass.SolrIndexSearcher.<init> Opening Searcher@2de7825b main
[junit4] 2> 1263161 T2779 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2de7825b main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1263164 T2778 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1263164 T2778 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:34631 collection:collection1 shard:shard1
[junit4] 2> 1263164 T2778 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1263176 T2778 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1263197 T2778 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1263208 T2778 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1263208 T2778 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1263208 T2778 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:34631/collection1/
[junit4] 2> 1263209 T2778 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1263209 T2778 oasc.SyncStrategy.syncToMe http://127.0.0.1:34631/collection1/ has no replicas
[junit4] 2> 1263209 T2778 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:34631/collection1/ shard1
[junit4] 2> 1263210 T2778 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1264213 T2758 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1264242 T2777 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> 1264242 T2764 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> 1264242 T2757 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> 1264244 T2778 oasc.ZkController.register We are http://127.0.0.1:34631/collection1/ and leader is http://127.0.0.1:34631/collection1/
[junit4] 2> 1264244 T2778 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34631
[junit4] 2> 1264244 T2778 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1264244 T2778 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1264244 T2778 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1264255 T2778 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1264256 T2735 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1264257 T2735 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1264257 T2735 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1264445 T2735 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1264449 T2735 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:34656
[junit4] 2> 1264449 T2735 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1264449 T2735 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1264450 T2735 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.SyncSliceTest-jetty2-1379126713520
[junit4] 2> 1264450 T2735 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty2-1379126713520/'
[junit4] 2> 1264477 T2735 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-jetty2-1379126713520/solr.xml
[junit4] 2> 1264538 T2735 oasc.CoreContainer.<init> New CoreContainer 519067381
[junit4] 2> 1264538 T2735 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.SyncSliceTest-jetty2-1379126713520/]
[junit4] 2> 1264540 T2735 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1264540 T2735 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1264540 T2735 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1264541 T2735 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1264541 T2735 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1264541 T2735 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1264542 T2735 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1264542 T2735 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1264542 T2735 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1264543 T2735 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1264554 T2735 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1264554 T2735 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1264555 T2735 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:34608/solr
[junit4] 2> 1264555 T2735 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1264556 T2735 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1264558 T2791 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54a9f848 name:ZooKeeperConnection Watcher:127.0.0.1:34608 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1264559 T2735 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1264560 T2735 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1264568 T2735 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1264570 T2793 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6efe2df0 name:ZooKeeperConnection Watcher:127.0.0.1:34608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1264570 T2735 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1264574 T2735 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1265582 T2735 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34656_
[junit4] 2> 1265593 T2735 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34656_
[junit4] 2> 1265613 T2764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1265617 T2777 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1265618 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1265618 T2757 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1265618 T2757 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1265618 T2793 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1265632 T2764 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1265665 T2794 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1265666 T2794 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1265669 T2794 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1265758 T2758 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1265759 T2758 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"active",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:34631_",
[junit4] 2> "base_url":"http://127.0.0.1:34631"}
[junit4] 2> 1265764 T2758 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:34656_",
[junit4] 2> "base_url":"http://127.0.0.1:34656"}
[junit4] 2> 1265765 T2758 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 1265765 T2758 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1265793 T2757 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> 1265793 T2764 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> 1265793 T2777 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> 1265793 T2793 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> 1266670 T2794 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1266671 T2794 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.SyncSliceTest-jetty2-1379126713520/collection1
[junit4] 2> 1266671 T2794 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1266692 T2794 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1266693 T2794 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1266694 T2794 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty2-1379126713520/collection1/'
[junit4] 2> 1266696 T2794 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-1379126713520/collection1/lib/classes/' to classloader
[junit4] 2> 1266696 T2794 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-1379126713520/collection1/lib/README' to classloader
[junit4] 2> 1266950 T2794 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1267178 T2794 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1267282 T2794 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1267309 T2794 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 1269211 T2794 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1269292 T2794 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1269296 T2794 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1269317 T2794 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1269335 T2794 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1269352 T2794 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1269354 T2794 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1269357 T2794 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1269357 T2794 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1269359 T2794 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1269360 T2794 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1269360 T2794 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1269361 T2794 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.SyncSliceTest-jetty2-1379126713520/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty2/
[junit4] 2> 1269361 T2794 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@65716a7e
[junit4] 2> 1269363 T2794 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty2
[junit4] 2> 1269364 T2794 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty2/index/
[junit4] 2> 1269364 T2794 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1269365 T2794 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty2/index
[junit4] 2> 1269366 T2794 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=639627132, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1269367 T2794 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2df2a09e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2a3e3552),segFN=segments_1,generation=1}
[junit4] 2> 1269367 T2794 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1269373 T2794 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1269374 T2794 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1269374 T2794 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1269374 T2794 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1269375 T2794 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1269375 T2794 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1269376 T2794 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1269376 T2794 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1269377 T2794 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1269378 T2794 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1269379 T2794 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1269379 T2794 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1269380 T2794 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1269380 T2794 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1269381 T2794 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1269477 T2794 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1269483 T2794 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1269483 T2794 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1269485 T2794 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=38, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7331740695332857]
[junit4] 2> 1269486 T2794 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2df2a09e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2a3e3552),segFN=segments_1,generation=1}
[junit4] 2> 1269486 T2794 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1269486 T2794 oass.SolrIndexSearcher.<init> Opening Searcher@16b69c64 main
[junit4] 2> 1269490 T2795 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16b69c64 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1269492 T2794 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1269492 T2794 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:34656 collection:collection1 shard:shard1
[junit4] 2> 1269493 T2794 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1269528 T2794 oasc.ZkController.register We are http://127.0.0.1:34656/collection1/ and leader is http://127.0.0.1:34631/collection1/
[junit4] 2> 1269528 T2794 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34656
[junit4] 2> 1269529 T2794 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 1269529 T2794 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C736 name=collection1 org.apache.solr.core.SolrCore@16f1b09e url=http://127.0.0.1:34656/collection1 node=127.0.0.1:34656_ C736_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:34656_, base_url=http://127.0.0.1:34656}
[junit4] 2> 1269530 T2796 C736 P34656 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 1269532 T2796 C736 P34656 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 1269532 T2794 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1269532 T2796 C736 P34656 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 1269532 T2796 C736 P34656 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1269534 T2796 C736 P34656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1269534 T2735 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1269535 T2735 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1269536 T2735 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1269573 T2767 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 1270097 T2735 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1270102 T2735 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:34685
[junit4] 2> 1270103 T2735 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1270103 T2735 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1270104 T2735 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-jetty3-1379126718822
[junit4] 2> 1270104 T2735 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-jetty3-1379126718822/'
[junit4] 2> 1270137 T2735 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-jetty3-1379126718822/solr.xml
[junit4] 2> 1270246 T2735 oasc.CoreContainer.<init> New CoreContainer 983093325
[junit4] 2> 1270246 T2735 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-jetty3-1379126718822/]
[junit4] 2> 1270248 T2735 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1270249 T2735 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1270249 T2735 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1270249 T2735 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1270250 T2735 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1270250 T2735 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1270251 T2735 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1270251 T2735 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1270251 T2735 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1270252 T2735 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1270277 T2735 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1270278 T2735 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1270279 T2735 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:34608/solr
[junit4] 2> 1270279 T2735 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1270280 T2735 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1270281 T2808 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4acdff19 name:ZooKeeperConnection Watcher:127.0.0.1:34608 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1270282 T2735 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1270284 T2735 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1270291 T2735 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1270293 T2810 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b9c5f15 name:ZooKeeperConnection Watcher:127.0.0.1:34608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1270293 T2735 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1270296 T2735 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1270340 T2758 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1270340 T2758 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"recovering",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:34656_",
[junit4] 2> "base_url":"http://127.0.0.1:34656"}
[junit4] 2> 1270343 T2757 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> 1270343 T2793 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> 1270343 T2810 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> 1270343 T2777 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> 1270343 T2764 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> 1270575 T2767 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 1270575 T2767 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=core_node2&state=recovering&nodeName=127.0.0.1:34656_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1002
[junit4] 2> 1271298 T2735 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34685_
[junit4] 2> 1271300 T2735 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34685_
[junit4] 2> 1271312 T2764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1271312 T2777 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1271312 T2810 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1271312 T2757 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1271312 T2793 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1271313 T2757 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1271314 T2764 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1271313 T2810 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1271312 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1271313 T2793 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1271323 T2811 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1271323 T2811 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1271325 T2811 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1271847 T2758 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1271848 T2758 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:34685_",
[junit4] 2> "base_url":"http://127.0.0.1:34685"}
[junit4] 2> 1271848 T2758 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 1271849 T2758 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1271865 T2757 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> 1271865 T2764 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> 1271865 T2810 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> 1271865 T2793 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> 1271865 T2777 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> 1272326 T2811 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1272327 T2811 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-jetty3-1379126718822/collection1
[junit4] 2> 1272327 T2811 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1272328 T2811 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1272329 T2811 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1272330 T2811 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-jetty3-1379126718822/collection1/'
[junit4] 2> 1272333 T2811 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-1379126718822/collection1/lib/README' to classloader
[junit4] 2> 1272334 T2811 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-1379126718822/collection1/lib/classes/' to classloader
[junit4] 2> 1272401 T2811 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1272466 T2811 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1272568 T2811 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> ASYNC NEW_CORE C737 name=collection1 org.apache.solr.core.SolrCore@16f1b09e url=http://127.0.0.1:34656/collection1 node=127.0.0.1:34656_ C737_STATE=coll:collection1 core:collection1 props:{state=recovering, core=collection1, node_name=127.0.0.1:34656_, base_url=http://127.0.0.1:34656}
[junit4] 2> 1272577 T2796 C737 P34656 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:34631/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4] 2> 1272577 T2796 C737 P34656 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:34656 START replicas=[http://127.0.0.1:34631/collection1/] nUpdates=100
[junit4] 2> 1272578 T2796 C737 P34656 oasu.PeerSync.sync WARN no frame of reference to tell if we've missed updates
[junit4] 2> 1272578 T2796 C737 P34656 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4] 2> 1272578 T2796 C737 P34656 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4] 2> 1272579 T2796 C737 P34656 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4] 2> 1272579 T2796 C737 P34656 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 1272579 T2796 C737 P34656 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:34631/collection1/. core=collection1
[junit4] 2> 1272579 T2796 C737 P34656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1272581 T2811 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> ASYNC NEW_CORE C738 name=collection1 org.apache.solr.core.SolrCore@517b28f6 url=http://127.0.0.1:34631/collection1 node=127.0.0.1:34631_ C738_STATE=coll:collection1 core:collection1 props:{state=active, core=collection1, node_name=127.0.0.1:34631_, base_url=http://127.0.0.1:34631, leader=true}
[junit4] 2> 1272587 T2768 C738 P34631 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4] 2> 1272592 T2769 C738 P34631 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1272592 T2769 C738 P34631 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1272593 T2769 C738 P34631 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 1272593 T2769 C738 P34631 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 2
[junit4] 2> 1272594 T2796 C737 P34656 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 1272594 T2796 C737 P34656 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 1272597 T2770 C738 P34631 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 1272597 T2770 C738 P34631 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 1272598 T2796 C737 P34656 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4] 2> 1272598 T2796 C737 P34656 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4] 2> 1272598 T2796 C737 P34656 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1272598 T2796 C737 P34656 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1272600 T2796 C737 P34656 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4] 2> 1273244 T2811 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1273257 T2811 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1273262 T2811 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1273277 T2811 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1273283 T2811 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1273287 T2811 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1273288 T2811 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1273289 T2811 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1273289 T2811 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1273290 T2811 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1273291 T2811 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1273291 T2811 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1273291 T2811 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-jetty3-1379126718822/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty3/
[junit4] 2> 1273292 T2811 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@65716a7e
[junit4] 2> 1273293 T2811 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty3
[junit4] 2> 1273293 T2811 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty3/index/
[junit4] 2> 1273293 T2811 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 1273294 T2811 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1379126703784/jetty3/index
[junit4] 2> 1273295 T2811 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=639627132, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1273296 T2811 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@569bbd8d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e9a7e4c),segFN=segments_1,generation=1}
[junit4] 2> 1273296 T2811 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1273301 T2811 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1273301 T2811 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1273302 T2811 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1273302 T2811 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1273302 T2811 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1273303 T2811 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1273303 T2811 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1273304 T2811 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1273304 T2811 oasc.SolrCore.loadUpdateProcessorChain
[...truncated too long message...]
solr.cloud.SyncSliceTest-1379126703784/jetty2
[junit4] 2> 1333332 T2793 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1333332 T2793 oasc.SolrException.log ERROR There was a problem trying to register as the leader:org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:184)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:181)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:181)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:392)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:361)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:348)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:95)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:255)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:156)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:100)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1333333 T2793 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election/90382447659712520-core_node2-n_0000000001
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:152)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:149)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:149)
[junit4] 2> at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:63)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:258)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:156)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:100)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1333369 T2793 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1333369 T2793 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1333369 T2793 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1333370 T2793 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:235)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:232)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:232)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1333370 T2793 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1333370 T2793 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene45: {range_facet_l=FSTOrd41, text=Pulsing41(freqCutoff=9 minBlockSize=11 maxBlockSize=117), _version_=FSTOrd41, rnd_b=MockVariableIntBlock(baseBlockSize=123), intDefault=FSTOrd41, timestamp=FSTOrd41, id=MockVariableIntBlock(baseBlockSize=123), a_t=FSTOrd41, range_facet_sl=Pulsing41(freqCutoff=9 minBlockSize=11 maxBlockSize=117), range_facet_si=PostingsFormat(name=NestedPulsing), other_tl1=FSTOrd41, multiDefault=PostingsFormat(name=NestedPulsing), a_si=PostingsFormat(name=NestedPulsing)}, docValues:{timestamp=DocValuesFormat(name=SimpleText)}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=en_NZ, timezone=Australia/Hobart
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=2,free=311580776,total=438304768
[junit4] 2> NOTE: All tests run in this JVM: [DeleteShardTest, QueryElevationComponentTest, TestConfig, TestBadConfig, ScriptEngineTest, TestRealTimeGet, CopyFieldTest, TestWriterPerf, TestPostingsSolrHighlighter, ShardSplitTest, TestReversedWildcardFilterFactory, OverseerTest, TestSystemIdResolver, SliceStateUpdateTest, WordBreakSolrSpellCheckerTest, ExternalFileFieldSortTest, IndexSchemaTest, ClusterStateTest, TestJmxMonitoredMap, QueryParsingTest, TestBM25SimilarityFactory, CircularListTest, JsonLoaderTest, DOMUtilTest, SearchHandlerTest, BlockCacheTest, TestCopyFieldCollectionResource, SOLR749Test, TestLMJelinekMercerSimilarityFactory, StatelessScriptUpdateProcessorFactoryTest, SystemInfoHandlerTest, ShardRoutingTest, SpellPossibilityIteratorTest, SolrCoreTest, LukeRequestHandlerTest, RegexBoostProcessorTest, TestDefaultSearchFieldResource, PrimitiveFieldTypeTest, OverseerCollectionProcessorTest, UpdateRequestProcessorFactoryTest, TestQueryUtils, ZkCLITest, TestLFUCache, LoggingHandlerTest, TestTrie, TestFaceting, TestPHPSerializedResponseWriter, ParsingFieldUpdateProcessorsTest, TestSuggestSpellingConverter, TestSolrQueryParser, LeaderElectionTest, SpatialFilterTest, HdfsUnloadDistributedZkTest, DistributedTermsComponentTest, AliasIntegrationTest, ZkControllerTest, HdfsRecoveryZkTest, TestGroupingSearch, SchemaVersionSpecificBehaviorTest, DirectUpdateHandlerOptimizeTest, BadCopyFieldTest, DistributedQueryElevationComponentTest, QueryResultKeyTest, TermsComponentTest, SampleTest, TestRecoveryHdfs, TestJoin, TestMergePolicyConfig, TestCoreContainer, TestSolrXmlPersistence, TestCharFilters, BasicDistributedZkTest, URLClassifyProcessorTest, TestMaxScoreQueryParser, ShowFileRequestHandlerTest, QueryEqualityTest, TestRandomDVFaceting, AnalysisAfterCoreReloadTest, SyncSliceTest]
[junit4] Completed on J0 in 79.52s, 1 test, 1 failure <<< FAILURES!
[...truncated 504 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:396: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:376: 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:455: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1230: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:873: There were test failures: 325 suites, 1446 tests, 1 failure, 34 ignored (6 assumptions)
Total time: 56 minutes 1 second
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure