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 23:56:57 UTC
[JENKINS] Lucene-Solr-Tests-4.x-Java7 - Build # 1721 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java7/1721/
All tests passed
Build Log:
[...truncated 26552 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-Java7/lucene/tools/forbiddenApis/base.txt
[forbidden-apis] Reading API signatures: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/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 1376 related) class file(s) for forbidden API invocations (in 2.73s), 1 error(s).
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:428: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:67: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build.xml:286: Check for forbidden API calls failed, see log.
Total time: 75 minutes 31 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-Java7 - Build # 1722 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java7/1722/
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
shard3 is not consistent. Got 111 from http://127.0.0.1:45508/collection1lastClient and got 104 from http://127.0.0.1:16717/collection1
Stack Trace:
java.lang.AssertionError: shard3 is not consistent. Got 111 from http://127.0.0.1:45508/collection1lastClient and got 104 from http://127.0.0.1:16717/collection1
at __randomizedtesting.SeedInfo.seed([FB62C30A4652421:8E50A228D33A441D]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1148)
at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:135)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 10356 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4] 2> 1578456 T4070 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 1578465 T4070 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./solrtest-ChaosMonkeySafeLeaderTest-1383311239291
[junit4] 2> 1578467 T4070 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1578468 T4071 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1578569 T4070 oasc.ZkTestServer.run start zk server on port:61541
[junit4] 2> 1578570 T4070 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1578574 T4077 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26fa2ac4 name:ZooKeeperConnection Watcher:127.0.0.1:61541 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1578574 T4070 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1578574 T4070 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1578590 T4070 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1578592 T4079 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6644f5d9 name:ZooKeeperConnection Watcher:127.0.0.1:61541/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1578592 T4070 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1578593 T4070 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1578600 T4070 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1578607 T4070 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1578609 T4070 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1578612 T4070 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1578612 T4070 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1578628 T4070 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 1578630 T4070 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1578733 T4070 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1578734 T4070 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1578737 T4070 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1578737 T4070 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1578748 T4070 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1578749 T4070 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1578752 T4070 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1578753 T4070 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1578755 T4070 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1578756 T4070 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1578763 T4070 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1578763 T4070 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1578766 T4070 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1578766 T4070 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1578769 T4070 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1578769 T4070 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1578961 T4070 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1578966 T4070 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:52156
[junit4] 2> 1578966 T4070 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1578967 T4070 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1578967 T4070 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1383311239603
[junit4] 2> 1578967 T4070 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1383311239603/'
[junit4] 2> 1578998 T4070 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1383311239603/solr.xml
[junit4] 2> 1579061 T4070 oasc.CoreContainer.<init> New CoreContainer 1982895620
[junit4] 2> 1579062 T4070 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1383311239603/]
[junit4] 2> 1579063 T4070 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1579064 T4070 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1579064 T4070 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1579064 T4070 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1579065 T4070 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1579065 T4070 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1579066 T4070 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1579066 T4070 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1579066 T4070 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1579071 T4070 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1579071 T4070 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1579072 T4070 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:61541/solr
[junit4] 2> 1579072 T4070 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1579073 T4070 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1579075 T4090 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a23e2f7 name:ZooKeeperConnection Watcher:127.0.0.1:61541 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1579076 T4070 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1579088 T4070 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1579092 T4092 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@44ffe43e name:ZooKeeperConnection Watcher:127.0.0.1:61541/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1579092 T4070 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1579094 T4070 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1579103 T4070 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1579107 T4070 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1579115 T4070 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52156_
[junit4] 2> 1579116 T4070 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52156_
[junit4] 2> 1579119 T4070 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1579135 T4070 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1579144 T4070 oasc.Overseer.start Overseer (id=90656685378699267-127.0.0.1:52156_-n_0000000000) starting
[junit4] 2> 1579153 T4070 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1579166 T4094 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1579166 T4070 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1579169 T4070 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1579170 T4070 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1579172 T4093 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1579178 T4095 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1579178 T4095 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1579180 T4095 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1580676 T4093 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1580677 T4093 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:52156",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52156_",
[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> 1580677 T4093 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1580678 T4093 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1580694 T4092 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> 1581182 T4095 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1581182 T4095 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1383311239603/collection1
[junit4] 2> 1581183 T4095 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1581183 T4095 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1581184 T4095 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1581184 T4095 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1383311239603/collection1/'
[junit4] 2> 1581186 T4095 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1383311239603/collection1/lib/README' to classloader
[junit4] 2> 1581187 T4095 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1383311239603/collection1/lib/classes/' to classloader
[junit4] 2> 1581286 T4095 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1581353 T4095 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1581455 T4095 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1581467 T4095 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1582222 T4095 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1582223 T4095 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1582224 T4095 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1582237 T4095 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1582241 T4095 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1582254 T4095 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1582259 T4095 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1582263 T4095 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1582264 T4095 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1582265 T4095 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1582265 T4095 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1582266 T4095 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1582266 T4095 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1582267 T4095 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 1582267 T4095 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1383311239603/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/control/data/
[junit4] 2> 1582268 T4095 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5d8b8d9e
[junit4] 2> 1582269 T4095 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/control/data
[junit4] 2> 1582270 T4095 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/control/data/index/
[junit4] 2> 1582271 T4095 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1582272 T4095 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/control/data/index
[junit4] 2> 1582273 T4095 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=30, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.22370998993624786]
[junit4] 2> 1582281 T4095 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 1582282 T4095 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1582286 T4095 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1582287 T4095 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1582287 T4095 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1582287 T4095 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1582288 T4095 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1582288 T4095 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1582289 T4095 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1582289 T4095 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1582290 T4095 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1582290 T4095 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1582291 T4095 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1582291 T4095 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1582292 T4095 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1582292 T4095 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1582293 T4095 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1582310 T4095 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1582314 T4095 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1582314 T4095 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1582315 T4095 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=50.2568359375, floorSegmentMB=0.666015625, forceMergeDeletesPctAllowed=2.358518745591459, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4880089201184772
[junit4] 2> 1582317 T4095 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 1582318 T4095 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1582318 T4095 oass.SolrIndexSearcher.<init> Opening Searcher@1ce12234 main
[junit4] 2> 1582322 T4096 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1ce12234 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1582323 T4095 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1582323 T4095 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52156 collection:control_collection shard:shard1
[junit4] 2> 1582325 T4095 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1582355 T4095 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1582359 T4095 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1582360 T4095 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1582361 T4095 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52156/collection1/
[junit4] 2> 1582361 T4095 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1582361 T4095 oasc.SyncStrategy.syncToMe http://127.0.0.1:52156/collection1/ has no replicas
[junit4] 2> 1582362 T4095 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52156/collection1/ shard1
[junit4] 2> 1582362 T4095 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1583700 T4093 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1583720 T4092 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> 1583756 T4095 oasc.ZkController.register We are http://127.0.0.1:52156/collection1/ and leader is http://127.0.0.1:52156/collection1/
[junit4] 2> 1583757 T4095 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52156
[junit4] 2> 1583757 T4095 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1583757 T4095 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1583758 T4095 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1583760 T4095 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1583762 T4070 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1583763 T4070 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1583766 T4070 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1583768 T4099 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6fb9cd5c name:ZooKeeperConnection Watcher:127.0.0.1:61541/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1583769 T4070 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1583770 T4070 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1583771 T4070 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 1584048 T4070 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1584052 T4070 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:18902
[junit4] 2> 1584053 T4070 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1584054 T4070 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1584054 T4070 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1383311244597
[junit4] 2> 1584055 T4070 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1383311244597/'
[junit4] 2> 1584098 T4070 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1383311244597/solr.xml
[junit4] 2> 1584191 T4070 oasc.CoreContainer.<init> New CoreContainer 1496944218
[junit4] 2> 1584192 T4070 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1383311244597/]
[junit4] 2> 1584194 T4070 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1584195 T4070 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1584195 T4070 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1584196 T4070 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1584196 T4070 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1584197 T4070 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1584197 T4070 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1584198 T4070 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1584198 T4070 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1584205 T4070 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1584206 T4070 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1584206 T4070 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:61541/solr
[junit4] 2> 1584207 T4070 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1584208 T4070 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1584211 T4110 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@132f55d4 name:ZooKeeperConnection Watcher:127.0.0.1:61541 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1584212 T4070 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1584227 T4070 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1584229 T4112 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7aa457bc name:ZooKeeperConnection Watcher:127.0.0.1:61541/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1584229 T4070 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1584240 T4070 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1585231 T4093 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1585232 T4093 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:52156",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52156_",
[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> 1585247 T4112 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> 1585247 T4070 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:18902_
[junit4] 2> 1585247 T4099 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> 1585247 T4092 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> 1585255 T4070 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:18902_
[junit4] 2> 1585258 T4099 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1585258 T4112 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1585258 T4092 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1585267 T4113 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1585268 T4113 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1585269 T4113 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1586757 T4093 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1586758 T4093 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:18902",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:18902_",
[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":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1586759 T4093 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1586759 T4093 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1586793 T4092 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> 1586793 T4099 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> 1586794 T4112 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> 1587272 T4113 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1587272 T4113 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1383311244597/collection1
[junit4] 2> 1587273 T4113 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1587273 T4113 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1587274 T4113 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1587275 T4113 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1383311244597/collection1/'
[junit4] 2> 1587277 T4113 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1383311244597/collection1/lib/README' to classloader
[junit4] 2> 1587278 T4113 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1383311244597/collection1/lib/classes/' to classloader
[junit4] 2> 1587348 T4113 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1587414 T4113 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1587516 T4113 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1587528 T4113 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1588187 T4113 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1588188 T4113 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1588189 T4113 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1588198 T4113 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1588201 T4113 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1588211 T4113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1588215 T4113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1588218 T4113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1588219 T4113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1588219 T4113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1588219 T4113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1588220 T4113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1588220 T4113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1588221 T4113 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 1588221 T4113 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1383311244597/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty1/
[junit4] 2> 1588221 T4113 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5d8b8d9e
[junit4] 2> 1588222 T4113 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty1
[junit4] 2> 1588223 T4113 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty1/index/
[junit4] 2> 1588223 T4113 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1588224 T4113 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty1/index
[junit4] 2> 1588225 T4113 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=30, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.22370998993624786]
[junit4] 2> 1588253 T4113 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 1588253 T4113 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1588257 T4113 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1588257 T4113 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1588258 T4113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1588258 T4113 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1588258 T4113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1588259 T4113 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1588259 T4113 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1588259 T4113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1588260 T4113 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1588260 T4113 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1588261 T4113 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1588261 T4113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1588261 T4113 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1588262 T4113 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1588262 T4113 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1588273 T4113 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1588276 T4113 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1588277 T4113 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1588277 T4113 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=50.2568359375, floorSegmentMB=0.666015625, forceMergeDeletesPctAllowed=2.358518745591459, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4880089201184772
[junit4] 2> 1588279 T4113 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 1588279 T4113 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1588279 T4113 oass.SolrIndexSearcher.<init> Opening Searcher@6c569248 main
[junit4] 2> 1588283 T4114 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6c569248 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1588285 T4113 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1588285 T4113 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:18902 collection:collection1 shard:shard1
[junit4] 2> 1588286 T4113 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1588307 T4113 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1588311 T4113 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1588311 T4113 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1588311 T4113 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:18902/collection1/
[junit4] 2> 1588311 T4113 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1588312 T4113 oasc.SyncStrategy.syncToMe http://127.0.0.1:18902/collection1/ has no replicas
[junit4] 2> 1588312 T4113 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:18902/collection1/ shard1
[junit4] 2> 1588312 T4113 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1589802 T4093 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1589827 T4099 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> 1589827 T4112 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> 1589827 T4092 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> 1589858 T4113 oasc.ZkController.register We are http://127.0.0.1:18902/collection1/ and leader is http://127.0.0.1:18902/collection1/
[junit4] 2> 1589858 T4113 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:18902
[junit4] 2> 1589858 T4113 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1589858 T4113 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1589858 T4113 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1589861 T4113 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1589862 T4070 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1589863 T4070 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1590156 T4070 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1590161 T4070 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:49762
[junit4] 2> 1590162 T4070 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1590162 T4070 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1590163 T4070 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1383311250690
[junit4] 2> 1590163 T4070 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1383311250690/'
[junit4] 2> 1590208 T4070 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1383311250690/solr.xml
[junit4] 2> 1590302 T4070 oasc.CoreContainer.<init> New CoreContainer 1822800944
[junit4] 2> 1590303 T4070 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1383311250690/]
[junit4] 2> 1590305 T4070 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1590306 T4070 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1590307 T4070 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1590307 T4070 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1590308 T4070 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1590308 T4070 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1590309 T4070 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1590309 T4070 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1590310 T4070 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1590317 T4070 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1590318 T4070 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1590319 T4070 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:61541/solr
[junit4] 2> 1590319 T4070 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1590320 T4070 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1590324 T4126 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b54f97e name:ZooKeeperConnection Watcher:127.0.0.1:61541 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1590325 T4070 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1590339 T4070 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1590341 T4128 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a4ec6bb name:ZooKeeperConnection Watcher:127.0.0.1:61541/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1590342 T4070 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1590354 T4070 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1591332 T4093 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1591333 T4093 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:18902",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:18902_",
[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":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1591349 T4099 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> 1591349 T4112 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> 1591349 T4092 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> 1591349 T4128 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> 1591357 T4070 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49762_
[junit4] 2> 1591359 T4070 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49762_
[junit4] 2> 1591362 T4099 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1591362 T4092 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1591362 T4128 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1591362 T4112 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1591377 T4129 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1591378 T4129 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1591379 T4129 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1592853 T4093 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1592854 T4093 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:49762",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49762_",
[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":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1592855 T4093 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1592855 T4093 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1592873 T4092 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> 1592873 T4112 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> 1592873 T4099 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> 1592873 T4128 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> 1593381 T4129 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1593381 T4129 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1383311250690/collection1
[junit4] 2> 1593382 T4129 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1593382 T4129 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1593383 T4129 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1593384 T4129 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1383311250690/collection1/'
[junit4] 2> 1593386 T4129 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1383311250690/collection1/lib/classes/' to classloader
[junit4] 2> 1593387 T4129 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1383311250690/collection1/lib/README' to classloader
[junit4] 2> 1593455 T4129 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1593520 T4129 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1593622 T4129 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1593636 T4129 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1594324 T4129 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1594325 T4129 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1594326 T4129 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1594338 T4129 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1594343 T4129 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1594356 T4129 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1594361 T4129 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1594365 T4129 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1594366 T4129 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1594367 T4129 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1594367 T4129 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1594368 T4129 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1594368 T4129 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1594369 T4129 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 1594369 T4129 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1383311250690/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty2/
[junit4] 2> 1594369 T4129 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5d8b8d9e
[junit4] 2> 1594371 T4129 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty2
[junit4] 2> 1594372 T4129 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty2/index/
[junit4] 2> 1594372 T4129 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1594373 T4129 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty2/index
[junit4] 2> 1594374 T4129 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=30, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.22370998993624786]
[junit4] 2> 1594378 T4129 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 1594379 T4129 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1594384 T4129 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1594384 T4129 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1594385 T4129 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1594385 T4129 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1594385 T4129 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1594386 T4129 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1594386 T4129 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1594387 T4129 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1594387 T4129 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1594388 T4129 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1594389 T4129 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1594389 T4129 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1594390 T4129 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1594390 T4129 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1594391 T4129 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1594408 T4129 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1594412 T4129 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1594413 T4129 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1594414 T4129 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=50.2568359375, floorSegmentMB=0.666015625, forceMergeDeletesPctAllowed=2.358518745591459, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4880089201184772
[junit4] 2> 1594416 T4129 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 1594416 T4129 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1594416 T4129 oass.SolrIndexSearcher.<init> Opening Searcher@1f4dd99c main
[junit4] 2> 1594421 T4130 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1f4dd99c main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1594424 T4129 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1594424 T4129 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49762 collection:collection1 shard:shard2
[junit4] 2> 1594426 T4129 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1594443 T4129 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1594453 T4129 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1594453 T4129 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1594454 T4129 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49762/collection1/
[junit4] 2> 1594454 T4129 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1594454 T4129 oasc.SyncStrategy.syncToMe http://127.0.0.1:49762/collection1/ has no replicas
[junit4] 2> 1594455 T4129 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49762/collection1/ shard2
[junit4] 2> 1594455 T4129 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1595879 T4093 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1595899 T4128 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> 1595899 T4099 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> 1595899 T4092 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> 1595899 T4112 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> 1595947 T4129 oasc.ZkController.register We are http://127.0.0.1:49762/collection1/ and leader is http://127.0.0.1:49762/collection1/
[junit4] 2> 1595947 T4129 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49762
[junit4] 2> 1595948 T4129 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1595948 T4129 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1595948 T4129 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1595951 T4129 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1595953 T4070 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1595954 T4070 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1596243 T4070 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1596247 T4070 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:65015
[junit4] 2> 1596248 T4070 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1596248 T4070 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1596249 T4070 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1383311256780
[junit4] 2> 1596249 T4070 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1383311256780/'
[junit4] 2> 1596296 T4070 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1383311256780/solr.xml
[junit4] 2> 1596391 T4070 oasc.CoreContainer.<init> New CoreContainer 975336890
[junit4] 2> 1596392 T4070 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1383311256780/]
[junit4] 2> 1596394 T4070 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1596395 T4070 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1596396 T4070 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1596396 T4070 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1596397 T4070 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1596397 T4070 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1596398 T4070 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1596398 T4070 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1596399 T4070 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1596406 T4070 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1596406 T4070 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1596407 T4070 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:61541/solr
[junit4] 2> 1596408 T4070 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1596409 T4070 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1596413 T4142 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@23206bb name:ZooKeeperConnection Watcher:127.0.0.1:61541 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1596414 T4070 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1596427 T4070 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1596429 T4144 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@619c90d2 name:ZooKeeperConnection Watcher:127.0.0.1:61541/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1596429 T4070 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1596440 T4070 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1597411 T4093 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1597412 T4093 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:49762",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49762_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1597429 T4099 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> 1597429 T4128 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> 1597429 T4092 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> 1597429 T4144 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> 1597429 T4112 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> 1597444 T4070 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:65015_
[junit4] 2> 1597447 T4070 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:65015_
[junit4] 2> 1597449 T4112 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1597450 T4144 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1597449 T4092 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1597449 T4099 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1597449 T4128 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1597465 T4145 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1597465 T4145 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1597467 T4145 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1598933 T4093 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1598934 T4093 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:65015",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:65015_",
[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":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1598935 T4093 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1598935 T4093 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 1598952 T4092 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> 1598952 T4099 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> 1598952 T4144 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> 1598952 T4128 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> 1598953 T4112 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> 1599469 T4145 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1599469 T4145 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1383311256780/collection1
[junit4] 2> 1599470 T4145 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1599470 T4145 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1599471 T4145 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1599472 T4145 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1383311256780/collection1/'
[junit4] 2> 1599474 T4145 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1383311256780/collection1/lib/README' to classloader
[junit4] 2> 1599474 T4145 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1383311256780/collection1/lib/classes/' to classloader
[junit4] 2> 1599543 T4145 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1599609 T4145 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1599711 T4145 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1599723 T4145 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1600384 T4145 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1600385 T4145 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1600386 T4145 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1600398 T4145 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1600402 T4145 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1600415 T4145 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1600419 T4145 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1600424 T4145 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1600425 T4145 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1600425 T4145 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1600425 T4145 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1600426 T4145 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1600426 T4145 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1600427 T4145 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 1600427 T4145 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1383311256780/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty3/
[junit4] 2> 1600428 T4145 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5d8b8d9e
[junit4] 2> 1600429 T4145 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty3
[junit4] 2> 1600430 T4145 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty3/index/
[junit4] 2> 1600430 T4145 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 1600431 T4145 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty3/index
[junit4] 2> 1600432 T4145 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=30, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.22370998993624786]
[junit4] 2> 1600436 T4145 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 1600436 T4145 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1600441 T4145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1600442 T4145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1600442 T4145 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1600443 T4145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1600443 T4145 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1600443 T4145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1600444 T4145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1600444 T4145 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1600444 T4145 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1600445 T4145 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1600446 T4145 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1600446 T4145 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1600447 T4145 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1600447 T4145 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1600448 T4145 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1600463 T4145 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1600467 T4145 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1600468 T4145 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1600469 T4145 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=50.2568359375, floorSegmentMB=0.666015625, forceMergeDeletesPctAllowed=2.358518745591459, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4880089201184772
[junit4] 2> 1600470 T4145 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 1600471 T4145 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1600471 T4145 oass.SolrIndexSearcher.<init> Opening Searcher@469ba61 main
[junit4] 2> 1600476 T4146 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@469ba61 main{StandardDirectoryReader
[...truncated too long message...]
oryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty12/index
[junit4] 2> 1761506 T4303 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty12 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty12;done=false>>]
[junit4] 2> 1761506 T4303 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1383311239291/jetty12
[junit4] 2> 1761506 T4303 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 1761507 T4303 oasc.SolrException.log ERROR There was a problem trying to register as the leader:org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:196)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:193)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:193)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:404)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:360)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:95)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:255)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:156)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:100)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1761507 T4303 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election/90656685378699292-core_node12-n_0000000003
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:164)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:161)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:161)
[junit4] 2> at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:63)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:258)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:156)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:100)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1761508 T4303 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1761508 T4303 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> 1761508 T4303 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1761508 T4303 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:247)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:244)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:244)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> NOTE: test params are: codec=Lucene3x, sim=DefaultSimilarity, locale=ga, timezone=Atlantic/Bermuda
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=2,free=290707584,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestIndexSearcher, ShowFileRequestHandlerTest, TestLMDirichletSimilarityFactory, AddBlockUpdateTest, TestRealTimeGet, TestManagedSchema, TestValueSourceCache, LeaderElectionTest, IndexBasedSpellCheckerTest, SliceStateTest, TestCollationField, TestXIncludeConfig, QueryElevationComponentTest, TestDFRSimilarityFactory, TestReloadAndDeleteDocs, TestReplicationHandler, TestFieldResource, OverseerTest, HdfsRecoveryZkTest, TestMergePolicyConfig, TestSearchPerf, TestDistributedGrouping, TestSolrXml, XmlUpdateRequestHandlerTest, SystemInfoHandlerTest, BadIndexSchemaTest, TestCloudManagedSchemaAddField, TestDocumentBuilder, TestFastOutputStream, TestSchemaSimilarityResource, TestSolrCoreProperties, ZkControllerTest, BasicZkTest, AutoCommitTest, TestExtendedDismaxParser, TestSolrIndexConfig, BJQParserTest, TestCopyFieldCollectionResource, TestPartialUpdateDeduplication, TestStressReorder, AliasIntegrationTest, DocValuesTest, PingRequestHandlerTest, TestSweetSpotSimilarityFactory, BadCopyFieldTest, TestNonNRTOpen, TestStressUserVersions, UnloadDistributedZkTest, CachingDirectoryFactoryTest, MoreLikeThisHandlerTest, DeleteReplicaTest, TestComponentsName, RecoveryZkTest, SpellCheckCollatorTest, TestSuggestSpellingConverter, TestManagedSchemaFieldResource, TestReload, TestFiltering, ConvertedLegacyTest, TestJmxIntegration, TestStressLucene, IndexSchemaRuntimeFieldTest, TestSolrQueryParserResource, ResponseLogComponentTest, SuggesterTest, TestWordDelimiterFilterFactory, SOLR749Test, CollectionsAPIDistributedZkTest, TestIBSimilarityFactory, TestDocSet, TestMaxScoreQueryParser, FieldAnalysisRequestHandlerTest, TestFuzzyAnalyzedSuggestions, SolrInfoMBeanTest, TestFieldCollectionResource, SampleTest, SpatialFilterTest, RAMDirectoryFactoryTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest]
[junit4] Completed on J0 in 184.09s, 1 test, 1 failure <<< FAILURES!
[...truncated 520 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:428: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:408: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/common-build.xml:483: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:1263: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:906: There were test failures: 333 suites, 1469 tests, 1 failure, 35 ignored (6 assumptions)
Total time: 68 minutes 24 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure