You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/11/28 18:07:48 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.8.0-ea-b117) - Build #
8398 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/8398/
Java: 32bit/jdk1.8.0-ea-b117 -client -XX:+UseG1GC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.testDistribSearch
Error Message:
shard1 is not consistent. Got 274 from http://127.0.0.1:36936/collection1lastClient and got 275 from http://127.0.0.1:57099/collection1
Stack Trace:
java.lang.AssertionError: shard1 is not consistent. Got 274 from http://127.0.0.1:36936/collection1lastClient and got 275 from http://127.0.0.1:57099/collection1
at __randomizedtesting.SeedInfo.seed([A49BF9145845B272:257D770C2F1AD24E]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1153)
at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.java:197)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
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:744)
Build Log:
[...truncated 11006 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest
[junit4] 2> 906530 T4401 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 906534 T4401 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-ChaosMonkeyNothingIsSafeTest-1385658114428
[junit4] 2> 906535 T4401 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 906535 T4402 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 906635 T4401 oasc.ZkTestServer.run start zk server on port:60296
[junit4] 2> 906646 T4401 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 906702 T4408 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@eb8529 name:ZooKeeperConnection Watcher:127.0.0.1:60296 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 906703 T4401 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 906703 T4401 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 906708 T4401 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 906709 T4410 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16d97b4 name:ZooKeeperConnection Watcher:127.0.0.1:60296/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 906709 T4401 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 906710 T4401 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 906713 T4401 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 906719 T4401 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 906722 T4401 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 906724 T4401 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 906725 T4401 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 906728 T4401 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 906729 T4401 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 906732 T4401 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 906732 T4401 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 906735 T4401 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 906735 T4401 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 906737 T4401 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 906738 T4401 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 906740 T4401 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 906741 T4401 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 906743 T4401 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 906743 T4401 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 906746 T4401 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 906746 T4401 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 906748 T4401 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 906749 T4401 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 906752 T4401 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 906752 T4401 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 906754 T4401 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 906755 T4401 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 906834 T4401 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 906839 T4401 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:48024
[junit4] 2> 906840 T4401 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 906841 T4401 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 906841 T4401 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1385658114652
[junit4] 2> 906842 T4401 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1385658114652/'
[junit4] 2> 906859 T4401 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1385658114652/solr.xml
[junit4] 2> 906872 T4401 oasc.CoreContainer.<init> New CoreContainer 23309183
[junit4] 2> 906872 T4401 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1385658114652/]
[junit4] 2> 906873 T4401 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 906874 T4401 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 906874 T4401 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 906875 T4401 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 906875 T4401 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 906876 T4401 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 906876 T4401 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 906877 T4401 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 906877 T4401 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 906882 T4401 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 906882 T4401 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 906883 T4401 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 906883 T4401 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60296/solr
[junit4] 2> 906883 T4401 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 906884 T4401 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 906886 T4421 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18cfe7c name:ZooKeeperConnection Watcher:127.0.0.1:60296 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 906886 T4401 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 906888 T4401 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 906889 T4423 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10e1e50 name:ZooKeeperConnection Watcher:127.0.0.1:60296/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 906889 T4401 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 906890 T4401 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 906893 T4401 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 906895 T4401 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 906897 T4401 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48024_
[junit4] 2> 906898 T4401 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48024_
[junit4] 2> 906900 T4401 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 906905 T4401 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 906907 T4401 oasc.Overseer.start Overseer (id=90810490187415555-127.0.0.1:48024_-n_0000000000) starting
[junit4] 2> 906911 T4401 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 906915 T4425 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 906916 T4401 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 906918 T4401 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 906920 T4401 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 906922 T4424 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 906924 T4426 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 906924 T4426 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 906925 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 906925 T4426 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 906926 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 906927 T4424 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:48024",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:48024_",
[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> 906927 T4424 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 906927 T4424 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 906929 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 906930 T4423 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> 907925 T4426 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 907926 T4426 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1385658114652/collection1
[junit4] 2> 907926 T4426 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 907926 T4426 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 907927 T4426 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 907928 T4426 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1385658114652/collection1/'
[junit4] 2> 907928 T4426 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1385658114652/collection1/lib/classes/' to classloader
[junit4] 2> 907929 T4426 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1385658114652/collection1/lib/README' to classloader
[junit4] 2> 907950 T4426 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 907960 T4426 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 907961 T4426 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 907969 T4426 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 908101 T4426 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 908102 T4426 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 908102 T4426 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 908107 T4426 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 908109 T4426 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 908119 T4426 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 908122 T4426 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 908124 T4426 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 908125 T4426 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 908125 T4426 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 908126 T4426 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 908126 T4426 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 908127 T4426 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 908127 T4426 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 908127 T4426 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1385658114652/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/control/data/
[junit4] 2> 908127 T4426 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@75c299
[junit4] 2> 908128 T4426 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/control/data
[junit4] 2> 908128 T4426 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/control/data/index/
[junit4] 2> 908129 T4426 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 908129 T4426 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/control/data/index
[junit4] 2> 908129 T4426 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=32.9111328125, floorSegmentMB=1.1533203125, forceMergeDeletesPctAllowed=24.03856333396047, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5196397867984802
[junit4] 2> 908173 T4426 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 908173 T4426 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 908175 T4426 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 908176 T4426 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 908176 T4426 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 908176 T4426 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 908177 T4426 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 908177 T4426 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 908177 T4426 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 908177 T4426 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 908178 T4426 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 908178 T4426 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 908179 T4426 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 908179 T4426 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 908179 T4426 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 908180 T4426 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 908180 T4426 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 908180 T4426 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 908182 T4426 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 908183 T4426 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 908183 T4426 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 908184 T4426 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=33, maxMergedSegmentMB=61.6005859375, floorSegmentMB=0.2216796875, forceMergeDeletesPctAllowed=4.595802320736166, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7315151494735418
[junit4] 2> 908185 T4426 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 908185 T4426 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 908185 T4426 oass.SolrIndexSearcher.<init> Opening Searcher@3f8f74 main
[junit4] 2> 908188 T4427 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3f8f74 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 908189 T4426 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 908189 T4426 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48024 collection:control_collection shard:shard1
[junit4] 2> 908190 T4426 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 908195 T4426 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 908197 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 908197 T4426 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 908197 T4426 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1266 name=collection1 org.apache.solr.core.SolrCore@1ff62af url=http://127.0.0.1:48024/collection1 node=127.0.0.1:48024_ C1266_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:48024, core=collection1, node_name=127.0.0.1:48024_}
[junit4] 2> 908198 T4426 C1266 P48024 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48024/collection1/
[junit4] 2> 908198 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 908198 T4426 C1266 P48024 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 908198 T4426 C1266 P48024 oasc.SyncStrategy.syncToMe http://127.0.0.1:48024/collection1/ has no replicas
[junit4] 2> 908199 T4426 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48024/collection1/ shard1
[junit4] 2> 908199 T4426 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 908201 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 908206 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 908209 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 908310 T4423 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> 908357 T4426 oasc.ZkController.register We are http://127.0.0.1:48024/collection1/ and leader is http://127.0.0.1:48024/collection1/
[junit4] 2> 908357 T4426 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48024
[junit4] 2> 908357 T4426 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 908357 T4426 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 908358 T4426 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 908359 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 908359 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 908359 T4426 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 908359 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 908360 T4401 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 908361 T4401 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 908361 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 908362 T4424 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:48024",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:48024_",
[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> 908363 T4401 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 908364 T4430 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14eca8d name:ZooKeeperConnection Watcher:127.0.0.1:60296/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 908364 T4401 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 908365 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 908365 T4401 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 908367 T4401 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 908442 T4401 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 908444 T4401 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47144
[junit4] 2> 908444 T4401 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 908445 T4401 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 908445 T4401 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1385658116262
[junit4] 2> 908446 T4401 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1385658116262/'
[junit4] 2> 908459 T4401 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1385658116262/solr.xml
[junit4] 2> 908467 T4430 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> 908467 T4423 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> 908469 T4401 oasc.CoreContainer.<init> New CoreContainer 17907647
[junit4] 2> 908469 T4401 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1385658116262/]
[junit4] 2> 908470 T4401 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 908470 T4401 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 908471 T4401 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 908471 T4401 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 908471 T4401 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 908472 T4401 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 908472 T4401 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 908472 T4401 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 908473 T4401 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 908476 T4401 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 908476 T4401 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 908476 T4401 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 908477 T4401 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60296/solr
[junit4] 2> 908477 T4401 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 908478 T4401 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 908479 T4441 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@299313 name:ZooKeeperConnection Watcher:127.0.0.1:60296 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 908479 T4401 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 908481 T4401 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 908482 T4443 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@130fc08 name:ZooKeeperConnection Watcher:127.0.0.1:60296/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 908482 T4401 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 908486 T4401 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 909489 T4401 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47144_
[junit4] 2> 909491 T4401 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47144_
[junit4] 2> 909493 T4443 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 909493 T4423 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 909494 T4430 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 909497 T4444 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 909498 T4444 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 909498 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 909498 T4444 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 909499 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 909499 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 909500 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 909501 T4424 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:47144",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:47144_",
[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":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 909501 T4424 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 909501 T4424 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 909504 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 909606 T4443 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> 909606 T4430 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> 909606 T4423 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> 910499 T4444 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 910499 T4444 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1385658116262/collection1
[junit4] 2> 910500 T4444 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 910500 T4444 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 910500 T4444 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 910502 T4444 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1385658116262/collection1/'
[junit4] 2> 910503 T4444 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1385658116262/collection1/lib/classes/' to classloader
[junit4] 2> 910503 T4444 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1385658116262/collection1/lib/README' to classloader
[junit4] 2> 910524 T4444 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 910534 T4444 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 910536 T4444 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 910543 T4444 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 910679 T4444 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 910679 T4444 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 910680 T4444 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 910684 T4444 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 910686 T4444 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 910696 T4444 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 910698 T4444 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 910700 T4444 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 910701 T4444 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 910701 T4444 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 910702 T4444 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 910702 T4444 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 910703 T4444 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 910703 T4444 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 910703 T4444 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1385658116262/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/jetty1/
[junit4] 2> 910703 T4444 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@75c299
[junit4] 2> 910704 T4444 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/jetty1
[junit4] 2> 910704 T4444 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/jetty1/index/
[junit4] 2> 910705 T4444 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 910705 T4444 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/jetty1/index
[junit4] 2> 910705 T4444 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=32.9111328125, floorSegmentMB=1.1533203125, forceMergeDeletesPctAllowed=24.03856333396047, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5196397867984802
[junit4] 2> 910707 T4444 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 910708 T4444 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 910710 T4444 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 910711 T4444 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 910711 T4444 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 910711 T4444 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 910711 T4444 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 910712 T4444 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 910712 T4444 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 910712 T4444 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 910713 T4444 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 910713 T4444 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 910714 T4444 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 910714 T4444 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 910714 T4444 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 910715 T4444 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 910715 T4444 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 910716 T4444 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 910718 T4444 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 910719 T4444 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 910719 T4444 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 910720 T4444 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=33, maxMergedSegmentMB=61.6005859375, floorSegmentMB=0.2216796875, forceMergeDeletesPctAllowed=4.595802320736166, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7315151494735418
[junit4] 2> 910721 T4444 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 910721 T4444 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 910721 T4444 oass.SolrIndexSearcher.<init> Opening Searcher@cb0257 main
[junit4] 2> 910726 T4445 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@cb0257 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 910728 T4444 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 910728 T4444 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:47144 collection:collection1 shard:shard2
[junit4] 2> 910729 T4444 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 910735 T4444 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 910736 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 910736 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 910737 T4444 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 910737 T4444 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 910737 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 910737 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C1267 name=collection1 org.apache.solr.core.SolrCore@e43874 url=http://127.0.0.1:47144/collection1 node=127.0.0.1:47144_ C1267_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:47144, core=collection1, node_name=127.0.0.1:47144_}
[junit4] 2> 910737 T4444 C1267 P47144 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:47144/collection1/
[junit4] 2> 910738 T4444 C1267 P47144 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 910738 T4444 C1267 P47144 oasc.SyncStrategy.syncToMe http://127.0.0.1:47144/collection1/ has no replicas
[junit4] 2> 910738 T4444 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:47144/collection1/ shard2
[junit4] 2> 910739 T4444 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 910741 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 910746 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 910749 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 910852 T4443 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> 910852 T4430 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> 910852 T4423 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> 910896 T4444 oasc.ZkController.register We are http://127.0.0.1:47144/collection1/ and leader is http://127.0.0.1:47144/collection1/
[junit4] 2> 910897 T4444 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47144
[junit4] 2> 910897 T4444 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 910897 T4444 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 910897 T4444 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 910899 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 910899 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 910899 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 910899 T4444 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 910900 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 910900 T4401 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 910901 T4424 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:47144",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:47144_",
[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":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 910901 T4401 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 910903 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 910971 T4401 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 910973 T4401 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36936
[junit4] 2> 910973 T4401 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 910974 T4401 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 910974 T4401 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1385658118796
[junit4] 2> 910974 T4401 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1385658118796/'
[junit4] 2> 910987 T4401 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1385658118796/solr.xml
[junit4] 2> 911005 T4443 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> 911005 T4401 oasc.CoreContainer.<init> New CoreContainer 13189945
[junit4] 2> 911006 T4401 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1385658118796/]
[junit4] 2> 911005 T4430 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> 911005 T4423 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> 911006 T4401 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 911007 T4401 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 911007 T4401 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 911008 T4401 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 911008 T4401 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 911008 T4401 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 911009 T4401 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 911009 T4401 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 911009 T4401 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 911012 T4401 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 911013 T4401 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 911013 T4401 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 911014 T4401 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60296/solr
[junit4] 2> 911014 T4401 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 911015 T4401 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 911016 T4457 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35ad04 name:ZooKeeperConnection Watcher:127.0.0.1:60296 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 911016 T4401 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 911018 T4401 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 911019 T4459 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9a5697 name:ZooKeeperConnection Watcher:127.0.0.1:60296/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 911019 T4401 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 911022 T4401 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 912025 T4401 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36936_
[junit4] 2> 912026 T4401 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36936_
[junit4] 2> 912028 T4443 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 912028 T4459 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 912028 T4430 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 912028 T4423 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 912032 T4460 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 912032 T4460 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 912033 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 912033 T4460 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 912033 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 912034 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 912035 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 912035 T4424 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:36936",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:36936_",
[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":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 912035 T4424 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 912036 T4424 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 912037 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 912141 T4443 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> 912141 T4423 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> 912141 T4459 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> 912141 T4430 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> 913034 T4460 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 913034 T4460 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1385658118796/collection1
[junit4] 2> 913034 T4460 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 913035 T4460 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 913035 T4460 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 913036 T4460 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1385658118796/collection1/'
[junit4] 2> 913037 T4460 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1385658118796/collection1/lib/classes/' to classloader
[junit4] 2> 913037 T4460 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1385658118796/collection1/lib/README' to classloader
[junit4] 2> 913059 T4460 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 913069 T4460 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 913070 T4460 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 913077 T4460 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 913217 T4460 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 913218 T4460 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 913218 T4460 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 913223 T4460 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 913224 T4460 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 913234 T4460 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 913236 T4460 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 913238 T4460 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 913239 T4460 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 913240 T4460 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 913240 T4460 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 913241 T4460 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 913241 T4460 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 913241 T4460 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 913241 T4460 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1385658118796/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/jetty2/
[junit4] 2> 913242 T4460 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@75c299
[junit4] 2> 913242 T4460 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/jetty2
[junit4] 2> 913243 T4460 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/jetty2/index/
[junit4] 2> 913243 T4460 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 913243 T4460 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/jetty2/index
[junit4] 2> 913244 T4460 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=32.9111328125, floorSegmentMB=1.1533203125, forceMergeDeletesPctAllowed=24.03856333396047, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5196397867984802
[junit4] 2> 913247 T4460 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 913247 T4460 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 913249 T4460 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 913250 T4460 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 913250 T4460 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 913250 T4460 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 913251 T4460 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 913251 T4460 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 913251 T4460 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 913252 T4460 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 913252 T4460 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 913252 T4460 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 913253 T4460 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 913253 T4460 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 913254 T4460 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 913254 T4460 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 913255 T4460 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 913255 T4460 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 913257 T4460 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 913258 T4460 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 913258 T4460 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 913259 T4460 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=33, maxMergedSegmentMB=61.6005859375, floorSegmentMB=0.2216796875, forceMergeDeletesPctAllowed=4.595802320736166, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7315151494735418
[junit4] 2> 913260 T4460 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1385658114428/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 913261 T4460 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 913261 T4460 oass.SolrIndexSearcher.<init> Opening Searcher@1747c31 main
[junit4] 2> 913265 T4461 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1747c31 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 913268 T4460 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 913268 T4460 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36936 collection:collection1 shard:shard1
[junit4] 2> 913269 T4460 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 913273 T4460 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 913274 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 913275 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 913275 T4460 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 913275 T4460 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 913275 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> ASYNC NEW_CORE C1268 name=collection1 org.apache.solr.core.SolrCore@16091d3 url=http://127.0.0.1:36936/collection1 node=127.0.0.1:36936_ C1268_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:36936, core=collection1, node_name=127.0.0.1:36936_}
[junit4] 2> 913275 T4460 C1268 P36936 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36936/collection1/
[junit4] 2> 913276 T4460 C1268 P36936 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 913276 T4460 C1268 P36936 oasc.SyncStrategy.syncToMe http://127.0.0.1:36936/collection1/ has no replicas
[junit4] 2> 913276 T4460 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36936/collection1/ shard1
[junit4] 2> 913276 T4460 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 913277 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 913279 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 913283 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 913286 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 913388 T4443 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> 913388 T4430 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> 913388 T4459 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> 913388 T4423 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> 913434 T4460 oasc.ZkController.register We are http://127.0.0.1:36936/collection1/ and leader is http://127.0.0.1:36936/collection1/
[junit4] 2> 913434 T4460 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36936
[junit4] 2> 913434 T4460 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 913435 T4460 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 913435 T4460 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 913436 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 913436 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 913436 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 913436 T4460 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 913437 T4401 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 913438 T4401 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 913438 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 913439 T4424 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:36936",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:36936_",
[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":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 913441 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 913508 T4401 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 913510 T4401 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49529
[junit4] 2> 913510 T4401 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 913511 T4401 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 913511 T4401 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1385658121333
[junit4] 2> 913511 T4401 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1385658121333/'
[junit4] 2> 913525 T4401 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1385658121333/solr.xml
[junit4] 2> 913534 T4401 oasc.CoreContainer.<init> New CoreContainer 13117553
[junit4] 2> 913534 T4401 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1385658121333/]
[junit4] 2> 913535 T4401 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 913535 T4401 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 913536 T4401 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 913536 T4401 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 913536 T4401 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 913537 T4401 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 913537 T4401 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 913537 T4401 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 913538 T4401 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 913541 T4401 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 913541 T4401 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 913542 T4401 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 913542 T4401 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60296/solr
[junit4] 2> 913542 T4401 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 913543 T4443 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> 913543 T4459 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> 913543 T4430 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> 913543 T4401 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 913543 T4423 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> 913546 T4473 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f7fec name:ZooKeeperConnection Watcher:127.0.0.1:60296 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 913546 T4401 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 913548 T4401 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 913549 T4475 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1715926 name:ZooKeeperConnection Watcher:127.0.0.1:60296/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 913549 T4401 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 913552 T4401 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 914555 T4401 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49529_
[junit4] 2> 914556 T4401 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49529_
[junit4] 2> 914558 T4443 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 914559 T4430 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 914559 T4459 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 914559 T4423 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 914559 T4475 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 914563 T4476 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 914563 T4476 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 914564 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 914564 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 914565 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 914564 T4476 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 914566 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 914567 T4424 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:49529",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49529_",
[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":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 914567 T4424 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 914567 T4424 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 914569 T4423 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 914671 T4443 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> 914672 T4430 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> 914672 T4423 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> 914672 T4475 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> 914672 T4459 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> 915565 T4476 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 915565 T4476 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1385658121333/collection1
[junit4] 2> 915566 T4476 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 915566 T4476 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 915567 T4476 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 915568 T4476 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1385658121333/collection1/'
[junit4] 2> 915569 T4476 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1385658121333/collection1/lib/classes/' to classloader
[junit4] 2> 915569 T4476 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1385658121333/collection1/lib/README' to classloader
[junit4] 2> 915590 T4476 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 915600 T4476 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 915602 T4476 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 915608 T4476 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 915739 T4476 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 915740 T4476 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 915740 T4476 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 915745 T4476 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 915746 T4476 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 915756 T4476 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 915758 T4476 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 915760 T4476 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 915761 T4476 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 915761 T4476 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 915761 T4476 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 915762 T4476 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 915762
[...truncated too long message...]
s":{"shard1":{
[junit4] 1> "range":"80000000-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{"core_node1":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:48024",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:48024_",
[junit4] 1> "leader":"true"}}}},
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "autoCreated":"true",
[junit4] 1> "maxShardsPerNode":"1"},
[junit4] 1> "collection1":{
[junit4] 1> "replicationFactor":"1",
[junit4] 1> "shards":{
[junit4] 1> "shard1":{
[junit4] 1> "range":"80000000-ffffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{
[junit4] 1> "core_node2":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:36936",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:36936_"},
[junit4] 1> "core_node4":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:57099",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:57099_",
[junit4] 1> "leader":"true"},
[junit4] 1> "core_node6":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:60483",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:60483_"}}},
[junit4] 1> "shard2":{
[junit4] 1> "range":"0-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{
[junit4] 1> "core_node1":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:47144",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:47144_",
[junit4] 1> "leader":"true"},
[junit4] 1> "core_node3":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:49529",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:49529_"},
[junit4] 1> "core_node5":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:42948",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:42948_"},
[junit4] 1> "core_node7":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:59491",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:59491_"}}}},
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "autoCreated":"true",
[junit4] 1> "maxShardsPerNode":"1"}}
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeyNothingIsSafeTest -Dtests.method=testDistribSearch -Dtests.seed=A49BF9145845B272 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=mk_MK -Dtests.timezone=AST -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 122s J0 | ChaosMonkeyNothingIsSafeTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: shard1 is not consistent. Got 274 from http://127.0.0.1:36936/collection1lastClient and got 275 from http://127.0.0.1:57099/collection1
[junit4] > at __randomizedtesting.SeedInfo.seed([A49BF9145845B272:257D770C2F1AD24E]:0)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1153)
[junit4] > at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.java:197)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 1028964 T4401 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 122438 T4400 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> 1029122 T4527 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1030207 T4545 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene45, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=mk_MK, timezone=AST
[junit4] 2> NOTE: Linux 3.8.0-33-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=5,free=103620864,total=268435456
[junit4] 2> NOTE: All tests run in this JVM: [TestCollapseQParserPlugin, CopyFieldTest, TestQueryUtils, AutoCommitTest, TestPseudoReturnFields, TestCollationFieldDocValues, MBeansHandlerTest, TestSchemaNameResource, HdfsLockFactoryTest, TestExtendedDismaxParser, SearchHandlerTest, TestShardHandlerFactory, ZkControllerTest, ResponseLogComponentTest, ZkCLITest, CachingDirectoryFactoryTest, ResourceLoaderTest, SystemInfoHandlerTest, StatelessScriptUpdateProcessorFactoryTest, UnloadDistributedZkTest, SliceStateTest, DeleteShardTest, TestDefaultSearchFieldResource, TestAnalyzeInfixSuggestions, TestClassNameShortening, SolrIndexSplitterTest, TestCharFilters, TestHighFrequencyDictionaryFactory, TermVectorComponentTest, TestLuceneMatchVersion, TermsComponentTest, TestValueSourceCache, TestSolrXmlPersistor, InfoHandlerTest, AnalysisAfterCoreReloadTest, ExternalFileFieldSortTest, SliceStateUpdateTest, TestManagedSchema, ClusterStateTest, TestSystemIdResolver, SchemaVersionSpecificBehaviorTest, TestLMDirichletSimilarityFactory, FieldMutatingUpdateProcessorTest, TestSchemaResource, UpdateParamsTest, TestCloudManagedSchemaAddField, SOLR749Test, SolrTestCaseJ4Test, IndexSchemaTest, TestLRUCache, SuggesterFSTTest, TestDocSet, TestBadConfig, TestLFUCache, FastVectorHighlighterTest, TestFaceting, TestPostingsSolrHighlighter, LeaderElectionTest, TestMaxScoreQueryParser, TestCoreContainer, TestBM25SimilarityFactory, UUIDFieldTest, TestReplicationHandler, PolyFieldTest, SampleTest, CSVRequestHandlerTest, ScriptEngineTest, UpdateRequestProcessorFactoryTest, TestRandomDVFaceting, URLClassifyProcessorTest, DateMathParserTest, HdfsCollectionsAPIDistributedZkTest, DOMUtilTest, TestElisionMultitermQuery, TestSolrXMLSerializer, DocValuesMissingTest, DistributedTermsComponentTest, OverseerCollectionProcessorTest, QueryElevationComponentTest, TestSolrQueryParser, TestSolrDeletionPolicy1, MoreLikeThisHandlerTest, TestReversedWildcardFilterFactory, SyncSliceTest, BasicDistributedZkTest, OpenCloseCoreStressTest, OverseerTest, ShardRoutingTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, TestRandomFaceting, TestJoin, SolrCmdDistributorTest, PeerSyncTest, BadIndexSchemaTest, TestSort, TestFunctionQuery, BasicFunctionalityTest, TestLazyCores, HighlighterTest, ShowFileRequestHandlerTest, DistributedQueryElevationComponentTest, CurrencyFieldXmlFileTest, SignatureUpdateProcessorFactoryTest, CoreAdminHandlerTest, SolrRequestParserTest, SuggesterTest, SpatialFilterTest, TestCSVLoader, SolrCoreCheckLockOnStartupTest, QueryEqualityTest, DefaultValueUpdateProcessorTest, DocValuesMultiTest, DebugComponentTest, CacheHeaderTest, TestSurroundQueryParser, DisMaxRequestHandlerTest, TestWriterPerf, DocumentAnalysisRequestHandlerTest, FileBasedSpellCheckerTest, TestIndexingPerformance, IndexSchemaRuntimeFieldTest, LoggingHandlerTest, ReturnFieldsTest, TestCSVResponseWriter, JsonLoaderTest, TestPHPSerializedResponseWriter, TestQuerySenderListener, TestSolrIndexConfig, BadComponentTest, TestMergePolicyConfig, TestSearchPerf, TestConfig, TestSolrCoreProperties, DirectSolrConnectionTest, TestPhraseSuggestions, TestCodecSupport, EchoParamsTest, TestNumberUtils, TestIBSimilarityFactory, TestJmxMonitoredMap, ChaosMonkeyNothingIsSafeTest]
[junit4] Completed on J0 in 123.73s, 1 test, 1 failure <<< FAILURES!
[...truncated 153 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:426: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:406: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1279: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:912: There were test failures: 346 suites, 1513 tests, 1 failure, 34 ignored (6 assumptions)
Total time: 45 minutes 23 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0-ea-b117 -client -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure