You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/10/31 22:39:22 UTC
[JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 2125 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/2125/
All tests passed
Build Log:
[...truncated 26012 lines...]
-check-forbidden-java-apis:
[forbidden-apis] Reading bundled API signatures: jdk-unsafe-1.6
[forbidden-apis] Reading bundled API signatures: jdk-deprecated-1.6
[forbidden-apis] Reading bundled API signatures: commons-io-unsafe-2.1
[forbidden-apis] Reading API signatures: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/tools/forbiddenApis/base.txt
[forbidden-apis] Reading API signatures: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/tools/forbiddenApis/servlet-api.txt
[forbidden-apis] Loading classes to check...
[forbidden-apis] Scanning for API signatures and dependencies...
[forbidden-apis] WARNING: The referenced class 'org.apache.lucene.collation.ICUCollationKeyAnalyzer' cannot be loaded. Please fix the classpath!
[forbidden-apis] WARNING: The referenced class 'org.apache.lucene.analysis.uima.ae.AEProviderFactory' cannot be loaded. Please fix the classpath!
[forbidden-apis] WARNING: The referenced class 'org.apache.lucene.analysis.uima.ae.AEProviderFactory' cannot be loaded. Please fix the classpath!
[forbidden-apis] WARNING: The referenced class 'org.apache.lucene.analysis.uima.ae.AEProvider' cannot be loaded. Please fix the classpath!
[forbidden-apis] Forbidden method invocation: java.util.concurrent.Executors#newFixedThreadPool(int) [Spawns threads with vague names; use a custom thread factory (Lucene's NamedThreadFactory, Solr's DefaultSolrThreadFactory) and name threads so that you can tell (by its name) which executor it is associated with]
[forbidden-apis] in org.apache.solr.update.TestDocBasedVersionConstraints (TestDocBasedVersionConstraints.java:361)
[forbidden-apis] Scanned 2515 (and 1373 related) class file(s) for forbidden API invocations (in 2.03s), 1 error(s).
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:428: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:67: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:286: Check for forbidden API calls failed, see log.
Total time: 75 minutes 36 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 2127 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/2127/
1 tests failed.
REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch
Error Message:
Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:45498/ri/hm/collection1 Dead Guy:http://127.0.0.1:37289/ri/hm/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:37633/ri/hm/collection1], CloudJettyRunner [url=http://127.0.0.1:37633/ri/hm/collection1]]
Stack Trace:
java.lang.AssertionError: Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:45498/ri/hm/collection1 Dead Guy:http://127.0.0.1:37289/ri/hm/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:37633/ri/hm/collection1], CloudJettyRunner [url=http://127.0.0.1:37633/ri/hm/collection1]]
at __randomizedtesting.SeedInfo.seed([758B462C8BCDEB5A:F46DC834FC928B66]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNotNull(Assert.java:526)
at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:216)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
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:679)
Build Log:
[...truncated 9658 lines...]
[junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4] 2> 1331044 T3559 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /ri/hm
[junit4] 2> 1331048 T3559 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-SyncSliceTest-1383326118501
[junit4] 2> 1331050 T3559 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1331051 T3560 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1331152 T3559 oasc.ZkTestServer.run start zk server on port:44387
[junit4] 2> 1331153 T3559 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1331157 T3566 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@189b99e6 name:ZooKeeperConnection Watcher:127.0.0.1:44387 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1331157 T3559 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1331158 T3559 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1331172 T3559 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1331174 T3568 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1eeb15d9 name:ZooKeeperConnection Watcher:127.0.0.1:44387/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1331174 T3559 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1331175 T3559 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1331185 T3559 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1331188 T3559 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1331190 T3559 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1331198 T3559 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1331198 T3559 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1331211 T3559 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 1331212 T3559 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1331315 T3559 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1331316 T3559 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1331319 T3559 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1331320 T3559 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1331329 T3559 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1331330 T3559 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1331332 T3559 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1331333 T3559 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1331336 T3559 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1331336 T3559 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1331344 T3559 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1331345 T3559 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1331347 T3559 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1331348 T3559 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1331351 T3559 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1331351 T3559 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1331624 T3559 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1331629 T3559 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:49039
[junit4] 2> 1331629 T3559 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1331630 T3559 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1331630 T3559 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1383326118813
[junit4] 2> 1331631 T3559 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1383326118813/'
[junit4] 2> 1331668 T3559 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1383326118813/solr.xml
[junit4] 2> 1331741 T3559 oasc.CoreContainer.<init> New CoreContainer 671285398
[junit4] 2> 1331741 T3559 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1383326118813/]
[junit4] 2> 1331743 T3559 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1331744 T3559 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1331744 T3559 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1331745 T3559 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1331745 T3559 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1331745 T3559 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1331746 T3559 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1331746 T3559 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1331747 T3559 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1331753 T3559 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1331754 T3559 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1331754 T3559 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44387/solr
[junit4] 2> 1331755 T3559 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1331756 T3559 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1331759 T3579 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d1b8c5f name:ZooKeeperConnection Watcher:127.0.0.1:44387 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1331759 T3559 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1331771 T3559 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1331773 T3581 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1374ba20 name:ZooKeeperConnection Watcher:127.0.0.1:44387/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1331774 T3559 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1331780 T3559 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1331784 T3559 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1331794 T3559 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1331796 T3559 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49039_ri%2Fhm
[junit4] 2> 1331803 T3559 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49039_ri%2Fhm
[junit4] 2> 1331805 T3559 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1331822 T3559 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1331825 T3559 oasc.Overseer.start Overseer (id=90657660502540291-127.0.0.1:49039_ri%2Fhm-n_0000000000) starting
[junit4] 2> 1331836 T3559 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1331847 T3583 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1331847 T3559 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1331850 T3559 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1331852 T3559 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1331854 T3582 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1331859 T3584 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1331860 T3584 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1331861 T3584 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1333357 T3582 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1333358 T3582 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:49039/ri/hm",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49039_ri%2Fhm",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1333358 T3582 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1333359 T3582 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1333379 T3581 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> 1333863 T3584 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1333863 T3584 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1383326118813/collection1
[junit4] 2> 1333863 T3584 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1333864 T3584 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1333864 T3584 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1333865 T3584 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1383326118813/collection1/'
[junit4] 2> 1333867 T3584 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-controljetty-1383326118813/collection1/lib/classes/' to classloader
[junit4] 2> 1333868 T3584 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-controljetty-1383326118813/collection1/lib/README' to classloader
[junit4] 2> 1333928 T3584 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1333988 T3584 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1334090 T3584 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1334101 T3584 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1334726 T3584 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1334726 T3584 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1334727 T3584 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1334739 T3584 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1334744 T3584 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1334756 T3584 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1334761 T3584 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1334765 T3584 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1334766 T3584 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1334766 T3584 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1334766 T3584 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1334767 T3584 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1334768 T3584 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1334768 T3584 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1334768 T3584 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1383326118813/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1383326118501/control/data/
[junit4] 2> 1334769 T3584 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@8e20e85
[junit4] 2> 1334769 T3584 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1383326118501/control/data
[junit4] 2> 1334770 T3584 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1383326118501/control/data/index/
[junit4] 2> 1334770 T3584 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1383326118501/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1334770 T3584 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1383326118501/control/data/index
[junit4] 2> 1334771 T3584 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=38, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=95.4462890625, floorSegmentMB=1.92578125, forceMergeDeletesPctAllowed=27.002008538196648, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1334772 T3584 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@10cccd03 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@112e80ca),segFN=segments_1,generation=1}
[junit4] 2> 1334772 T3584 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1334775 T3584 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1334775 T3584 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1334776 T3584 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1334776 T3584 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1334776 T3584 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1334777 T3584 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1334777 T3584 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1334778 T3584 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1334778 T3584 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1334778 T3584 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1334779 T3584 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1334779 T3584 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1334779 T3584 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1334780 T3584 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1334780 T3584 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1334790 T3584 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1334796 T3584 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1334796 T3584 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1334797 T3584 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=29.7333984375, floorSegmentMB=1.306640625, forceMergeDeletesPctAllowed=14.627929060783886, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6292717203003031
[junit4] 2> 1334797 T3584 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@10cccd03 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@112e80ca),segFN=segments_1,generation=1}
[junit4] 2> 1334798 T3584 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1334798 T3584 oass.SolrIndexSearcher.<init> Opening Searcher@4a6d0155 main
[junit4] 2> 1334801 T3585 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4a6d0155 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1334803 T3584 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1334803 T3584 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49039/ri/hm collection:control_collection shard:shard1
[junit4] 2> 1334804 T3584 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1334822 T3584 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1334825 T3584 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1334825 T3584 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1334826 T3584 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49039/ri/hm/collection1/
[junit4] 2> 1334826 T3584 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1334826 T3584 oasc.SyncStrategy.syncToMe http://127.0.0.1:49039/ri/hm/collection1/ has no replicas
[junit4] 2> 1334826 T3584 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49039/ri/hm/collection1/ shard1
[junit4] 2> 1334827 T3584 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1334883 T3582 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1334898 T3581 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> 1334942 T3584 oasc.ZkController.register We are http://127.0.0.1:49039/ri/hm/collection1/ and leader is http://127.0.0.1:49039/ri/hm/collection1/
[junit4] 2> 1334942 T3584 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49039/ri/hm
[junit4] 2> 1334942 T3584 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1334942 T3584 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1334943 T3584 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1334944 T3584 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1334945 T3559 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4] 2> 1334946 T3559 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1334948 T3559 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1334950 T3588 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2039790 name:ZooKeeperConnection Watcher:127.0.0.1:44387/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1334951 T3559 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1334952 T3559 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1334954 T3559 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 1335226 T3559 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1335228 T3559 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:37289
[junit4] 2> 1335229 T3559 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1335229 T3559 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1335230 T3559 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1383326122406
[junit4] 2> 1335230 T3559 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1383326122406/'
[junit4] 2> 1335267 T3559 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1383326122406/solr.xml
[junit4] 2> 1335340 T3559 oasc.CoreContainer.<init> New CoreContainer 1811578979
[junit4] 2> 1335341 T3559 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1383326122406/]
[junit4] 2> 1335343 T3559 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1335343 T3559 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1335344 T3559 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1335344 T3559 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1335345 T3559 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1335345 T3559 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1335345 T3559 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1335346 T3559 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1335346 T3559 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1335353 T3559 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1335354 T3559 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1335354 T3559 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44387/solr
[junit4] 2> 1335355 T3559 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1335356 T3559 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1335359 T3599 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b031af7 name:ZooKeeperConnection Watcher:127.0.0.1:44387 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1335359 T3559 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1335374 T3559 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1335376 T3601 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29743a9a name:ZooKeeperConnection Watcher:127.0.0.1:44387/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1335376 T3559 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1335380 T3559 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1336383 T3559 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37289_ri%2Fhm
[junit4] 2> 1336386 T3559 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37289_ri%2Fhm
[junit4] 2> 1336389 T3581 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1336389 T3601 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1336389 T3588 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1336403 T3582 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1336403 T3582 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:49039/ri/hm",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49039_ri%2Fhm",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1336404 T3602 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1336404 T3602 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1336406 T3602 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1336408 T3582 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:37289/ri/hm",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37289_ri%2Fhm",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1336408 T3582 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1336408 T3582 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1336412 T3601 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> 1336412 T3581 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> 1336412 T3588 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> 1337407 T3602 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1337407 T3602 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1383326122406/collection1
[junit4] 2> 1337407 T3602 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1337408 T3602 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1337408 T3602 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1337409 T3602 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1383326122406/collection1/'
[junit4] 2> 1337411 T3602 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty1-1383326122406/collection1/lib/README' to classloader
[junit4] 2> 1337412 T3602 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty1-1383326122406/collection1/lib/classes/' to classloader
[junit4] 2> 1337473 T3602 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1337539 T3602 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1337640 T3602 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1337651 T3602 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1338269 T3602 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1338269 T3602 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1338270 T3602 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1338282 T3602 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1338286 T3602 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1338299 T3602 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1338303 T3602 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1338307 T3602 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1338308 T3602 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1338309 T3602 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1338309 T3602 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1338310 T3602 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1338310 T3602 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1338310 T3602 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1338311 T3602 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1383326122406/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty1/
[junit4] 2> 1338311 T3602 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@8e20e85
[junit4] 2> 1338312 T3602 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty1
[junit4] 2> 1338312 T3602 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty1/index/
[junit4] 2> 1338312 T3602 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1338313 T3602 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty1/index
[junit4] 2> 1338313 T3602 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=38, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=95.4462890625, floorSegmentMB=1.92578125, forceMergeDeletesPctAllowed=27.002008538196648, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1338314 T3602 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2e8b741b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@68aff031),segFN=segments_1,generation=1}
[junit4] 2> 1338314 T3602 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1338318 T3602 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1338318 T3602 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1338319 T3602 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1338319 T3602 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1338319 T3602 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1338320 T3602 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1338320 T3602 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1338321 T3602 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1338321 T3602 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1338322 T3602 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1338322 T3602 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1338322 T3602 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1338323 T3602 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1338323 T3602 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1338324 T3602 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1338333 T3602 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1338338 T3602 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1338339 T3602 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1338339 T3602 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=29.7333984375, floorSegmentMB=1.306640625, forceMergeDeletesPctAllowed=14.627929060783886, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6292717203003031
[junit4] 2> 1338340 T3602 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2e8b741b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@68aff031),segFN=segments_1,generation=1}
[junit4] 2> 1338340 T3602 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1338341 T3602 oass.SolrIndexSearcher.<init> Opening Searcher@3717134d main
[junit4] 2> 1338345 T3603 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3717134d main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1338347 T3602 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1338347 T3602 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37289/ri/hm collection:collection1 shard:shard1
[junit4] 2> 1338349 T3602 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1338369 T3602 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1338379 T3602 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1338380 T3602 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1338380 T3602 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37289/ri/hm/collection1/
[junit4] 2> 1338380 T3602 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1338380 T3602 oasc.SyncStrategy.syncToMe http://127.0.0.1:37289/ri/hm/collection1/ has no replicas
[junit4] 2> 1338381 T3602 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37289/ri/hm/collection1/ shard1
[junit4] 2> 1338381 T3602 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1339420 T3582 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1339443 T3601 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> 1339443 T3581 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> 1339443 T3588 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> 1339466 T3602 oasc.ZkController.register We are http://127.0.0.1:37289/ri/hm/collection1/ and leader is http://127.0.0.1:37289/ri/hm/collection1/
[junit4] 2> 1339466 T3602 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37289/ri/hm
[junit4] 2> 1339466 T3602 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1339466 T3602 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1339467 T3602 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1339468 T3602 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1339469 T3559 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4] 2> 1339470 T3559 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1339737 T3559 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1339740 T3559 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:37633
[junit4] 2> 1339740 T3559 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1339741 T3559 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1339741 T3559 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.SyncSliceTest-jetty2-1383326126923
[junit4] 2> 1339742 T3559 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty2-1383326126923/'
[junit4] 2> 1339778 T3559 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1383326126923/solr.xml
[junit4] 2> 1339851 T3559 oasc.CoreContainer.<init> New CoreContainer 1519838291
[junit4] 2> 1339852 T3559 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.SyncSliceTest-jetty2-1383326126923/]
[junit4] 2> 1339853 T3559 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1339854 T3559 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1339854 T3559 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1339855 T3559 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1339855 T3559 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1339856 T3559 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1339856 T3559 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1339856 T3559 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1339857 T3559 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1339863 T3559 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1339864 T3559 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1339865 T3559 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44387/solr
[junit4] 2> 1339865 T3559 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1339866 T3559 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1339869 T3615 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6868339b name:ZooKeeperConnection Watcher:127.0.0.1:44387 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1339869 T3559 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1339886 T3559 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1339889 T3617 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43bb7c09 name:ZooKeeperConnection Watcher:127.0.0.1:44387/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1339889 T3559 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1339900 T3559 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1340903 T3559 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37633_ri%2Fhm
[junit4] 2> 1340914 T3559 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37633_ri%2Fhm
[junit4] 2> 1340917 T3588 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1340917 T3617 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1340917 T3601 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1340917 T3581 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1340937 T3618 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1340937 T3618 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1340939 T3618 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1340948 T3582 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1340948 T3582 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:37289/ri/hm",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37289_ri%2Fhm",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1340952 T3582 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:37633/ri/hm",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37633_ri%2Fhm",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1340952 T3582 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 1340952 T3582 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1340965 T3617 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> 1340965 T3581 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> 1340965 T3588 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> 1340965 T3601 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> 1341940 T3618 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1341940 T3618 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.SyncSliceTest-jetty2-1383326126923/collection1
[junit4] 2> 1341940 T3618 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1341941 T3618 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1341941 T3618 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1341942 T3618 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty2-1383326126923/collection1/'
[junit4] 2> 1341944 T3618 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty2-1383326126923/collection1/lib/classes/' to classloader
[junit4] 2> 1341944 T3618 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty2-1383326126923/collection1/lib/README' to classloader
[junit4] 2> 1342005 T3618 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1342066 T3618 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1342168 T3618 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1342179 T3618 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1342799 T3618 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1342799 T3618 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1342800 T3618 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1342812 T3618 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1342817 T3618 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1342829 T3618 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1342833 T3618 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1342837 T3618 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1342838 T3618 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1342839 T3618 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1342839 T3618 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1342840 T3618 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1342840 T3618 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1342840 T3618 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1342841 T3618 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.SyncSliceTest-jetty2-1383326126923/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty2/
[junit4] 2> 1342841 T3618 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@8e20e85
[junit4] 2> 1342842 T3618 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty2
[junit4] 2> 1342842 T3618 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty2/index/
[junit4] 2> 1342842 T3618 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1342843 T3618 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty2/index
[junit4] 2> 1342843 T3618 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=38, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=95.4462890625, floorSegmentMB=1.92578125, forceMergeDeletesPctAllowed=27.002008538196648, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1342844 T3618 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7805463b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@76855a4c),segFN=segments_1,generation=1}
[junit4] 2> 1342844 T3618 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1342848 T3618 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1342848 T3618 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1342849 T3618 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1342849 T3618 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1342849 T3618 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1342850 T3618 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1342850 T3618 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1342851 T3618 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1342851 T3618 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1342852 T3618 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1342852 T3618 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1342852 T3618 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1342853 T3618 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1342853 T3618 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1342854 T3618 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1342863 T3618 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1342868 T3618 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1342869 T3618 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1342869 T3618 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=29.7333984375, floorSegmentMB=1.306640625, forceMergeDeletesPctAllowed=14.627929060783886, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6292717203003031
[junit4] 2> 1342870 T3618 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7805463b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@76855a4c),segFN=segments_1,generation=1}
[junit4] 2> 1342870 T3618 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1342871 T3618 oass.SolrIndexSearcher.<init> Opening Searcher@77063119 main
[junit4] 2> 1342874 T3619 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@77063119 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1342876 T3618 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1342877 T3618 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37633/ri/hm collection:collection1 shard:shard1
[junit4] 2> 1342896 T3618 oasc.ZkController.register We are http://127.0.0.1:37633/ri/hm/collection1/ and leader is http://127.0.0.1:37289/ri/hm/collection1/
[junit4] 2> 1342897 T3618 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37633/ri/hm
[junit4] 2> 1342897 T3618 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 1342897 T3618 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C1168 name=collection1 org.apache.solr.core.SolrCore@60e0213c url=http://127.0.0.1:37633/ri/hm/collection1 node=127.0.0.1:37633_ri%2Fhm C1168_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:37633/ri/hm, core=collection1, node_name=127.0.0.1:37633_ri%2Fhm}
[junit4] 2> 1342897 T3620 C1168 P37633 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 1342897 T3618 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1342898 T3620 C1168 P37633 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 1342898 T3620 C1168 P37633 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 1342898 T3620 C1168 P37633 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1342898 T3559 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4] 2> 1342899 T3559 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1342901 T3591 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 1343072 T3559 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1343074 T3559 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:45498
[junit4] 2> 1343075 T3559 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1343075 T3559 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1343075 T3559 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.SyncSliceTest-jetty3-1383326130352
[junit4] 2> 1343076 T3559 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty3-1383326130352/'
[junit4] 2> 1343100 T3559 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1383326130352/solr.xml
[junit4] 2> 1343147 T3559 oasc.CoreContainer.<init> New CoreContainer 1149456010
[junit4] 2> 1343148 T3559 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.SyncSliceTest-jetty3-1383326130352/]
[junit4] 2> 1343149 T3559 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1343149 T3559 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1343150 T3559 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1343150 T3559 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1343150 T3559 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1343150 T3559 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1343151 T3559 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1343151 T3559 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1343151 T3559 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1343156 T3559 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1343156 T3559 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1343156 T3559 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44387/solr
[junit4] 2> 1343157 T3559 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1343157 T3559 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1343160 T3632 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@899692a name:ZooKeeperConnection Watcher:127.0.0.1:44387 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1343160 T3559 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1343177 T3559 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1343179 T3634 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@21514776 name:ZooKeeperConnection Watcher:127.0.0.1:44387/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1343180 T3559 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1343184 T3559 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1343980 T3582 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1343981 T3582 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "base_url":"http://127.0.0.1:37633/ri/hm",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37633_ri%2Fhm",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1344023 T3617 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> 1344023 T3588 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> 1344023 T3581 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> 1344023 T3601 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> 1344023 T3634 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> 1344187 T3559 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45498_ri%2Fhm
[junit4] 2> 1344189 T3559 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45498_ri%2Fhm
[junit4] 2> 1344191 T3601 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1344192 T3581 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1344192 T3588 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1344191 T3617 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1344192 T3634 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1344206 T3635 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1344207 T3635 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1344208 T3635 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1344904 T3591 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4] 2> 1344904 T3591 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=core_node2&state=recovering&nodeName=127.0.0.1:37633_ri%252Fhm&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2003
[junit4] 2> 1345527 T3582 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1345528 T3582 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:45498/ri/hm",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:45498_ri%2Fhm",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1345528 T3582 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 1345528 T3582 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1345545 T3581 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> 1345545 T3588 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> 1345545 T3634 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> 1345545 T3601 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> 1345545 T3617 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> 1346211 T3635 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1346211 T3635 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.SyncSliceTest-jetty3-1383326130352/collection1
[junit4] 2> 1346211 T3635 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1346212 T3635 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1346212 T3635 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1346213 T3635 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty3-1383326130352/collection1/'
[junit4] 2> 1346215 T3635 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty3-1383326130352/collection1/lib/classes/' to classloader
[junit4] 2> 1346215 T3635 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty3-1383326130352/collection1/lib/README' to classloader
[junit4] 2> 1346275 T3635 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1346342 T3635 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1346444 T3635 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1346455 T3635 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> ASYNC NEW_CORE C1169 name=collection1 org.apache.solr.core.SolrCore@60e0213c url=http://127.0.0.1:37633/ri/hm/collection1 node=127.0.0.1:37633_ri%2Fhm C1169_STATE=coll:collection1 core:collection1 props:{state=recovering, base_url=http://127.0.0.1:37633/ri/hm, core=collection1, node_name=127.0.0.1:37633_ri%2Fhm}
[junit4] 2> 1346906 T3620 C1169 P37633 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:37289/ri/hm/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4] 2> 1346906 T3620 C1169 P37633 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:37633/ri/hm START replicas=[http://127.0.0.1:37289/ri/hm/collection1/] nUpdates=100
[junit4] 2> 1346907 T3620 C1169 P37633 oasu.PeerSync.sync WARN no frame of reference to tell if we've missed updates
[junit4] 2> 1346907 T3620 C1169 P37633 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4] 2> 1346907 T3620 C1169 P37633 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4] 2> 1346907 T3620 C1169 P37633 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4] 2> 1346908 T3620 C1169 P37633 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 1346908 T3620 C1169 P37633 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:37289/ri/hm/collection1/. core=collection1
[junit4] 2> ASYNC NEW_CORE C1170 name=collection1 org.apache.solr.core.SolrCore@33781250 url=http://127.0.0.1:37289/ri/hm/collection1 node=127.0.0.1:37289_ri%2Fhm C1170_STATE=coll:collection1 core:collection1 props:{state=active, base_url=http://127.0.0.1:37289/ri/hm, core=collection1, node_name=127.0.0.1:37289_ri%2Fhm, leader=true}
[junit4] 2> 1346916 T3592 C1170 P37289 oasc.SolrCore.execute [collection1] webapp=/ri/hm path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4] 2> 1346919 T3593 C1170 P37289 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1346919 T3593 C1170 P37289 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1346920 T3593 C1170 P37289 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 1346920 T3593 C1170 P37289 oasup.LogUpdateProcessor.finish [collection1] webapp=/ri/hm path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 2
[junit4] 2> 1346921 T3620 C1169 P37633 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> ASYNC NEW_CORE C1171 name=collection1 org.apache.solr.core.SolrCore@60e0213c url=http://127.0.0.1:37633/ri/hm/collection1 node=127.0.0.1:37633_ri%2Fhm C1171_STATE=coll:collection1 core:collection1 props:{state=recovering, base_url=http://127.0.0.1:37633/ri/hm, core=collection1, node_name=127.0.0.1:37633_ri%2Fhm}
[junit4] 2> 1346921 T3620 C1171 P37633 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> ASYNC NEW_CORE C1172 name=collection1 org.apache.solr.core.SolrCore@33781250 url=http://127.0.0.1:37289/ri/hm/collection1 node=127.0.0.1:37289_ri%2Fhm C1172_STATE=coll:collection1 core:collection1 props:{state=active, base_url=http://127.0.0.1:37289/ri/hm, core=collection1, node_name=127.0.0.1:37289_ri%2Fhm, leader=true}
[junit4] 2> 1346929 T3594 C1172 P37289 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 1346929 T3594 C1172 P37289 oasc.SolrCore.execute [collection1] webapp=/ri/hm path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 1346930 T3620 C1171 P37633 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4] 2> 1346930 T3620 C1171 P37633 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4] 2> 1346931 T3620 C1171 P37633 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1346931 T3620 C1171 P37633 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1346936 T3620 C1171 P37633 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4] 2> 1347049 T3582 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1347050 T3582 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:37633/ri/hm",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37633_ri%2Fhm",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1347077 T3635 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1347078 T3635 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1347078 T3635 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1347086 T3635 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1347089 T3635 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1347137 T3634 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> 1347137 T3588 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> 1347137 T3581 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> 1347137 T3617 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> 1347137 T3601 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> 1347174 T3635 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1347179 T3635 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1347183 T3635 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1347184 T3635 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1347185 T3635 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1347185 T3635 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1347186 T3635 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1347186 T3635 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1347186 T3635 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1347187 T3635 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.SyncSliceTest-jetty3-1383326130352/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty3/
[junit4] 2> 1347187 T3635 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@8e20e85
[junit4] 2> 1347188 T3635 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty3
[junit4] 2> 1347188 T3635 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty3/index/
[junit4] 2> 1347189 T3635 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 1347189 T3635 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1383326118501/jetty3/index
[junit4] 2> 1347189 T3635 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=38, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=95.4462890625, floorSegmentMB=1.92578125, forceMergeDeletesPctAllowed=27.002008538196648, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1347190 T3635 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5fdb0f6f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5fd5814b),segFN=segments_1,generation=1}
[junit4] 2> 1347191 T3635 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1347194 T3635 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1347195 T3635 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1347195 T3635 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1347195 T3635 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1347196 T3635 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1347196 T3635 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1347197 T3635 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1347197 T3635 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1347197 T3635 oasc.SolrCore.loadUpdateProcessorChains no update
[...truncated too long message...]
maxShardsPerNode":"1",
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "replicationFactor":"1",
[junit4] 1> "autoCreated":"true"},
[junit4] 1> "control_collection":{
[junit4] 1> "shards":{"shard1":{
[junit4] 1> "range":"80000000-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{"core_node1":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:49039/ri/hm",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:49039_ri%2Fhm",
[junit4] 1> "leader":"true"}}}},
[junit4] 1> "maxShardsPerNode":"1",
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "replicationFactor":"1",
[junit4] 1> "autoCreated":"true"}}
[junit4] 1> /solr/aliases.json (0)
[junit4] 1> /solr/live_nodes (5)
[junit4] 1> /solr/live_nodes/127.0.0.1:37289_ri%2Fhm (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:54657_ri%2Fhm (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:37633_ri%2Fhm (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:45498_ri%2Fhm (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:49039_ri%2Fhm (0)
[junit4] 1> /solr/overseer (3)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1> /solr/overseer/queue (0)
[junit4] 1> /solr/overseer/queue-work (0)
[junit4] 1> /solr/overseer/collection-queue-work (0)
[junit4] 1> /solr/collections (2)
[junit4] 1> /solr/collections/collection1 (3)
[junit4] 1> DATA:
[junit4] 1> {"configName":"conf1"}
[junit4] 1> /solr/collections/collection1/shards (0)
[junit4] 1> /solr/collections/collection1/leader_elect (1)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election (4)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90657660502540296-core_node2-n_0000000004 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90657660502540298-core_node3-n_0000000002 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90657660502540302-core_node1-n_0000000005 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90657660502540300-core_node4-n_0000000003 (0)
[junit4] 1> /solr/collections/collection1/leaders (1)
[junit4] 1> /solr/collections/collection1/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:45498_ri%2Fhm",
[junit4] 1> "base_url":"http://127.0.0.1:45498/ri/hm"}
[junit4] 1> /solr/collections/control_collection (3)
[junit4] 1> DATA:
[junit4] 1> {"configName":"conf1"}
[junit4] 1> /solr/collections/control_collection/shards (0)
[junit4] 1> /solr/collections/control_collection/leader_elect (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election/90657660502540291-core_node1-n_0000000000 (0)
[junit4] 1> /solr/collections/control_collection/leaders (1)
[junit4] 1> /solr/collections/control_collection/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:49039_ri%2Fhm",
[junit4] 1> "base_url":"http://127.0.0.1:49039/ri/hm"}
[junit4] 1> /solr/overseer_elect (2)
[junit4] 1> /solr/overseer_elect/election (5)
[junit4] 1> /solr/overseer_elect/election/90657660502540291-127.0.0.1:49039_ri%2Fhm-n_0000000000 (0)
[junit4] 1> /solr/overseer_elect/election/90657660502540302-127.0.0.1:37289_ri%2Fhm-n_0000000005 (0)
[junit4] 1> /solr/overseer_elect/election/90657660502540300-127.0.0.1:54657_ri%2Fhm-n_0000000004 (0)
[junit4] 1> /solr/overseer_elect/election/90657660502540296-127.0.0.1:37633_ri%2Fhm-n_0000000002 (0)
[junit4] 1> /solr/overseer_elect/election/90657660502540298-127.0.0.1:45498_ri%2Fhm-n_0000000003 (0)
[junit4] 1> /solr/overseer_elect/leader (0)
[junit4] 1> DATA:
[junit4] 1> {"id":"90657660502540291-127.0.0.1:49039_ri%2Fhm-n_0000000000"}
[junit4] 1> /zookeeper (1)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SyncSliceTest -Dtests.method=testDistribSearch -Dtests.seed=758B462C8BCDEB5A -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=mk_MK -Dtests.timezone=Pacific/Guadalcanal -Dtests.file.encoding=UTF-8
[junit4] FAILURE 110s J0 | SyncSliceTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:45498/ri/hm/collection1 Dead Guy:http://127.0.0.1:37289/ri/hm/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:37633/ri/hm/collection1], CloudJettyRunner [url=http://127.0.0.1:37633/ri/hm/collection1]]
[junit4] > at __randomizedtesting.SeedInfo.seed([758B462C8BCDEB5A:F46DC834FC928B66]:0)
[junit4] > at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:216)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:679)
[junit4] 2> 1440654 T3559 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 109615 T3558 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4] 2> 1440807 T3634 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1441901 T3652 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene42, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=mk_MK, timezone=Pacific/Guadalcanal
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=1,free=163175824,total=395902976
[junit4] 2> NOTE: All tests run in this JVM: [QueryParsingTest, PolyFieldTest, TestLRUCache, TestLMJelinekMercerSimilarityFactory, DocValuesTest, TestSolrQueryParserResource, TestSolrXmlPersistor, QueryEqualityTest, PeerSyncTest, CachingDirectoryFactoryTest, SliceStateTest, CacheHeaderTest, CoreMergeIndexesAdminHandlerTest, TestElisionMultitermQuery, TestFaceting, BlockDirectoryTest, UpdateRequestProcessorFactoryTest, SynonymTokenizerTest, TestRandomDVFaceting, HdfsBasicDistributedZkTest, TestValueSourceCache, TestFieldTypeCollectionResource, MoreLikeThisHandlerTest, UUIDFieldTest, HdfsChaosMonkeySafeLeaderTest, ShardRoutingTest, TestSchemaNameResource, BinaryUpdateRequestHandlerTest, TestNoOpRegenerator, SpatialFilterTest, IndexSchemaTest, TestInfoStreamLogging, OverseerCollectionProcessorTest, TermsComponentTest, TestSolrXMLSerializer, TestSort, SOLR749Test, EchoParamsTest, ParsingFieldUpdateProcessorsTest, SystemInfoHandlerTest, SpellPossibilityIteratorTest, TestLFUCache, CSVRequestHandlerTest, HdfsDirectoryTest, TestReplicationHandler, SolrCoreTest, TestLuceneMatchVersion, TestFieldResource, WordBreakSolrSpellCheckerTest, StatelessScriptUpdateProcessorFactoryTest, TestPseudoReturnFields, TestCloudManagedSchemaAddField, TestMaxScoreQueryParser, SimpleFacetsTest, QueryElevationComponentTest, RegexBoostProcessorTest, BasicFunctionalityTest, TestSolrIndexConfig, TestSystemIdResolver, SoftAutoCommitTest, TestNRTOpen, ExternalFileFieldSortTest, ReturnFieldsTest, ScriptEngineTest, OverseerTest, TestFieldTypeResource, ResponseLogComponentTest, CustomCollectionTest, LukeRequestHandlerTest, FastVectorHighlighterTest, TestPerFieldSimilarity, SearchHandlerTest, TestSurroundQueryParser, TestReversedWildcardFilterFactory, SuggesterTest, StressHdfsTest, ZkCLITest, TestJoin, TestStressVersions, TestConfig, BasicDistributedZkTest, BasicDistributedZk2Test, UnloadDistributedZkTest, SyncSliceTest]
[junit4] Completed on J0 in 110.90s, 1 test, 1 failure <<< FAILURES!
[...truncated 617 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:428: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:408: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/common-build.xml:483: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1263: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:906: There were test failures: 333 suites, 1469 tests, 1 failure, 35 ignored (6 assumptions)
Total time: 60 minutes 33 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 2126 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/2126/
All tests passed
Build Log:
[...truncated 32665 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:428: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:367: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/extra-targets.xml:66: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/extra-targets.xml:135: The following files are missing svn:eol-style (or binary svn:mime-type):
* ./solr/core/src/java/org/apache/solr/update/processor/DocBasedVersionConstraintsProcessorFactory.java
* ./solr/core/src/test/org/apache/solr/cloud/TestDistribDocBasedVersion.java
* ./solr/core/src/test/org/apache/solr/search/TestStressUserVersions.java
* ./solr/core/src/test/org/apache/solr/update/TestDocBasedVersionConstraints.java
Total time: 75 minutes 0 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure