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/06/28 11:27:39 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.8.0-ea-b94) - Build #
6274 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/6274/
Java: 64bit/jdk1.8.0-ea-b94 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.testDistribSearch
Error Message:
shard1 is not consistent. Got 188 from http://127.0.0.1:43713/collection1lastClient and got 187 from http://127.0.0.1:42355/collection1
Stack Trace:
java.lang.AssertionError: shard1 is not consistent. Got 188 from http://127.0.0.1:43713/collection1lastClient and got 187 from http://127.0.0.1:42355/collection1
at __randomizedtesting.SeedInfo.seed([E7BEBAEF4DB0C807:665834F73AEFA83B]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1018)
at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.java:194)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:491)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 10198 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest
[junit4:junit4] 2> 891160 T2656 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 891167 T2656 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeyNothingIsSafeTest-1372411483702
[junit4:junit4] 2> 891168 T2656 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 891168 T2657 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 891268 T2656 oasc.ZkTestServer.run start zk server on port:43472
[junit4:junit4] 2> 891269 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 891278 T2663 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11be5878 name:ZooKeeperConnection Watcher:127.0.0.1:43472 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 891279 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 891279 T2656 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 891284 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 891285 T2658 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f8a1956380000, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4:junit4] 2>
[junit4:junit4] 2> 891289 T2665 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f79a43f name:ZooKeeperConnection Watcher:127.0.0.1:43472/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 891291 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 891291 T2656 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 891295 T2656 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 891298 T2656 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 891304 T2656 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 891307 T2656 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:junit4] 2> 891307 T2656 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 891312 T2656 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:junit4] 2> 891313 T2656 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 891316 T2656 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:junit4] 2> 891317 T2656 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 891320 T2656 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:junit4] 2> 891320 T2656 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 891323 T2656 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:junit4] 2> 891323 T2656 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 891325 T2656 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:junit4] 2> 891326 T2656 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 891329 T2656 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:junit4] 2> 891329 T2656 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 891333 T2656 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:junit4] 2> 891333 T2656 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 891336 T2656 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:junit4] 2> 891336 T2656 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 891341 T2658 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f8a1956380001, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4:junit4] 2>
[junit4:junit4] 2> 891421 T2656 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 891435 T2656 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40775
[junit4:junit4] 2> 891435 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 891436 T2656 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 891436 T2656 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1372411483874
[junit4:junit4] 2> 891437 T2656 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1372411483874/solr.xml
[junit4:junit4] 2> 891437 T2656 oasc.CoreContainer.<init> New CoreContainer 469201766
[junit4:junit4] 2> 891437 T2656 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1372411483874/'
[junit4:junit4] 2> 891438 T2656 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1372411483874/'
[junit4:junit4] 2> 891480 T2656 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 891481 T2656 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 891481 T2656 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 891481 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 891482 T2656 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 891482 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 891482 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 891483 T2656 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 891483 T2656 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 891483 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 891490 T2656 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 891490 T2656 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43472/solr
[junit4:junit4] 2> 891491 T2656 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 891491 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 891493 T2676 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7990e10e name:ZooKeeperConnection Watcher:127.0.0.1:43472 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 891494 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 891499 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 891503 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 891505 T2678 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26e4f0fc name:ZooKeeperConnection Watcher:127.0.0.1:43472/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 891505 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 891507 T2656 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 891511 T2656 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 891515 T2656 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 891517 T2656 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40775_
[junit4:junit4] 2> 891518 T2656 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40775_
[junit4:junit4] 2> 891522 T2656 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 891528 T2656 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 891531 T2656 oasc.Overseer.start Overseer (id=89942358996025347-127.0.0.1:40775_-n_0000000000) starting
[junit4:junit4] 2> 891536 T2656 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 891540 T2680 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 891541 T2656 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 891548 T2656 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 891550 T2656 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 891553 T2679 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 891556 T2681 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 891556 T2681 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 893057 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 893058 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:40775_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:40775"}
[junit4:junit4] 2> 893058 T2679 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 893058 T2679 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 893062 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 893559 T2681 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1372411483874/collection1
[junit4:junit4] 2> 893559 T2681 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 893560 T2681 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 893560 T2681 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 893562 T2681 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1372411483874/collection1/'
[junit4:junit4] 2> 893562 T2681 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1372411483874/collection1/lib/README' to classloader
[junit4:junit4] 2> 893563 T2681 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1372411483874/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 893635 T3 oasu.ConcurrentLRUCache.finalize ERROR ConcurrentLRUCache was not destroyed prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!!
[junit4:junit4] 2> 893637 T2681 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 893671 T2681 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 893672 T2681 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 893684 T2681 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 894095 T2681 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 894096 T2681 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 894096 T2681 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 894103 T2681 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 894106 T2681 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 894126 T2681 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 894129 T2681 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 894133 T2681 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 894134 T2681 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 894134 T2681 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 894134 T2681 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 894135 T2681 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 894135 T2681 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 894136 T2681 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 894136 T2681 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1372411483874/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/control/data/
[junit4:junit4] 2> 894136 T2681 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@212dd9fd
[junit4:junit4] 2> 894136 T2681 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 894137 T2681 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/control/data
[junit4:junit4] 2> 894138 T2681 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/control/data/index/
[junit4:junit4] 2> 894138 T2681 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 894138 T2681 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/control/data/index
[junit4:junit4] 2> 894141 T2681 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/control/data/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 894141 T2681 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 894143 T2681 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 894143 T2681 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 894144 T2681 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 894145 T2681 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 894145 T2681 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 894145 T2681 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 894145 T2681 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 894146 T2681 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 894146 T2681 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 894148 T2681 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 894151 T2681 oass.SolrIndexSearcher.<init> Opening Searcher@7664650e main
[junit4:junit4] 2> 894152 T2681 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 894152 T2681 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 894156 T2682 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7664650e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 894158 T2681 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 894158 T2681 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:40775 collection:control_collection shard:shard1
[junit4:junit4] 2> 894159 T2681 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 894172 T2681 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 894175 T2681 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 894176 T2681 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 894176 T2681 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:40775/collection1/
[junit4:junit4] 2> 894176 T2681 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 894176 T2681 oasc.SyncStrategy.syncToMe http://127.0.0.1:40775/collection1/ has no replicas
[junit4:junit4] 2> 894177 T2681 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:40775/collection1/
[junit4:junit4] 2> 894177 T2681 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 894566 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 894575 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 894592 T2681 oasc.ZkController.register We are http://127.0.0.1:40775/collection1/ and leader is http://127.0.0.1:40775/collection1/
[junit4:junit4] 2> 894593 T2681 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:40775
[junit4:junit4] 2> 894593 T2681 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 894593 T2681 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 894593 T2681 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 894595 T2681 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 894596 T2656 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 894597 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 894597 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 894603 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 894604 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 894607 T2685 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49115911 name:ZooKeeperConnection Watcher:127.0.0.1:43472/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 894608 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 894610 T2656 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 894614 T2656 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 894697 T2656 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 894699 T2656 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:43713
[junit4:junit4] 2> 894700 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 894701 T2656 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 894701 T2656 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1372411487149
[junit4:junit4] 2> 894701 T2656 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1372411487149/solr.xml
[junit4:junit4] 2> 894702 T2656 oasc.CoreContainer.<init> New CoreContainer 1808675646
[junit4:junit4] 2> 894702 T2656 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1372411487149/'
[junit4:junit4] 2> 894703 T2656 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1372411487149/'
[junit4:junit4] 2> 894752 T2656 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 894752 T2656 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 894753 T2656 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 894753 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 894753 T2656 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 894754 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 894754 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 894754 T2656 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 894755 T2656 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 894755 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 894760 T2656 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 894761 T2656 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43472/solr
[junit4:junit4] 2> 894762 T2656 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 894763 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 894767 T2696 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5df05088 name:ZooKeeperConnection Watcher:127.0.0.1:43472 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 894768 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 894772 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 894777 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 894780 T2698 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b2819c0 name:ZooKeeperConnection Watcher:127.0.0.1:43472/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 894780 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 894784 T2656 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 895788 T2656 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43713_
[junit4:junit4] 2> 895789 T2656 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43713_
[junit4:junit4] 2> 895792 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 895793 T2685 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 895793 T2698 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 895795 T2678 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 895799 T2699 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 895799 T2699 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 896084 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 896085 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:40775__collection1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:40775_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:40775"}
[junit4:junit4] 2> 896089 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:43713_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:43713"}
[junit4:junit4] 2> 896089 T2679 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 896090 T2679 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 896094 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 896094 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 896094 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 896801 T2699 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1372411487149/collection1
[junit4:junit4] 2> 896801 T2699 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 896803 T2699 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 896803 T2699 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 896805 T2699 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1372411487149/collection1/'
[junit4:junit4] 2> 896806 T2699 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1372411487149/collection1/lib/README' to classloader
[junit4:junit4] 2> 896806 T2699 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1372411487149/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 896841 T2699 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 896888 T2699 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 896890 T2699 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 896897 T2699 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 897318 T2699 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 897319 T2699 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 897319 T2699 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 897327 T2699 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 897330 T2699 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 897348 T2699 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 897352 T2699 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 897355 T2699 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 897357 T2699 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 897362 T2699 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 897363 T2699 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 897364 T2699 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 897364 T2699 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 897364 T2699 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 897365 T2699 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1372411487149/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty1/
[junit4:junit4] 2> 897365 T2699 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@212dd9fd
[junit4:junit4] 2> 897365 T2699 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 897370 T2699 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty1
[junit4:junit4] 2> 897370 T2699 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty1/index/
[junit4:junit4] 2> 897370 T2699 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 897371 T2699 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty1/index
[junit4:junit4] 2> 897377 T2699 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty1/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 897378 T2699 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 897381 T2699 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 897381 T2699 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 897384 T2699 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 897385 T2699 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 897385 T2699 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 897385 T2699 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 897386 T2699 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 897386 T2699 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 897387 T2699 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 897388 T2699 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 897391 T2699 oass.SolrIndexSearcher.<init> Opening Searcher@5b2d6c7f main
[junit4:junit4] 2> 897392 T2699 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 897392 T2699 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 897399 T2700 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5b2d6c7f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 897403 T2699 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 897404 T2699 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43713 collection:collection1 shard:shard1
[junit4:junit4] 2> 897405 T2699 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 897411 T2699 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 897414 T2699 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 897414 T2699 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 897414 T2699 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:43713/collection1/
[junit4:junit4] 2> 897414 T2699 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 897415 T2699 oasc.SyncStrategy.syncToMe http://127.0.0.1:43713/collection1/ has no replicas
[junit4:junit4] 2> 897415 T2699 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:43713/collection1/
[junit4:junit4] 2> 897415 T2699 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 897600 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 897609 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 897609 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 897610 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 897621 T2699 oasc.ZkController.register We are http://127.0.0.1:43713/collection1/ and leader is http://127.0.0.1:43713/collection1/
[junit4:junit4] 2> 897621 T2699 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43713
[junit4:junit4] 2> 897622 T2699 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 897622 T2699 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 897622 T2699 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 897624 T2699 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 897625 T2656 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 897625 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 897626 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 897707 T2656 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 897710 T2656 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50158
[junit4:junit4] 2> 897711 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 897711 T2656 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 897711 T2656 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1372411490165
[junit4:junit4] 2> 897711 T2656 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1372411490165/solr.xml
[junit4:junit4] 2> 897712 T2656 oasc.CoreContainer.<init> New CoreContainer 1654702624
[junit4:junit4] 2> 897712 T2656 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1372411490165/'
[junit4:junit4] 2> 897712 T2656 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1372411490165/'
[junit4:junit4] 2> 897754 T2656 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 897754 T2656 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 897754 T2656 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 897755 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 897755 T2656 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 897755 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 897755 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 897756 T2656 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 897756 T2656 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 897756 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 897760 T2656 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 897760 T2656 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43472/solr
[junit4:junit4] 2> 897760 T2656 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 897761 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 897763 T2712 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6ab8966b name:ZooKeeperConnection Watcher:127.0.0.1:43472 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 897763 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 897765 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 897769 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 897771 T2714 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cb47f14 name:ZooKeeperConnection Watcher:127.0.0.1:43472/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 897771 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 897775 T2656 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 898779 T2656 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50158_
[junit4:junit4] 2> 898780 T2656 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50158_
[junit4:junit4] 2> 898783 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 898783 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 898783 T2685 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 898784 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 898784 T2714 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 898785 T2698 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 898786 T2678 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 898790 T2715 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 898790 T2715 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 899115 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 899116 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:43713__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:43713_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:43713"}
[junit4:junit4] 2> 899120 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50158_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50158"}
[junit4:junit4] 2> 899120 T2679 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 899120 T2679 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 899123 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 899123 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 899124 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 899125 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 899792 T2715 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1372411490165/collection1
[junit4:junit4] 2> 899792 T2715 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 899793 T2715 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 899793 T2715 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 899794 T2715 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1372411490165/collection1/'
[junit4:junit4] 2> 899795 T2715 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1372411490165/collection1/lib/README' to classloader
[junit4:junit4] 2> 899795 T2715 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1372411490165/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 899824 T2715 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 899863 T2715 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 899865 T2715 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 899871 T2715 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 900217 T2715 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 900218 T2715 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 900218 T2715 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 900224 T2715 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 900227 T2715 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 900240 T2715 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 900243 T2715 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 900247 T2715 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 900248 T2715 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 900249 T2715 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 900249 T2715 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 900250 T2715 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 900250 T2715 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 900250 T2715 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 900250 T2715 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1372411490165/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty2/
[junit4:junit4] 2> 900251 T2715 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@212dd9fd
[junit4:junit4] 2> 900251 T2715 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 900251 T2715 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty2
[junit4:junit4] 2> 900252 T2715 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty2/index/
[junit4:junit4] 2> 900252 T2715 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 900252 T2715 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty2/index
[junit4:junit4] 2> 900255 T2715 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty2/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 900255 T2715 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 900257 T2715 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 900258 T2715 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 900258 T2715 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 900259 T2715 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 900260 T2715 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 900260 T2715 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 900260 T2715 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 900261 T2715 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 900262 T2715 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 900264 T2715 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 900266 T2715 oass.SolrIndexSearcher.<init> Opening Searcher@7d716b0 main
[junit4:junit4] 2> 900267 T2715 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 900267 T2715 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 900279 T2716 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7d716b0 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 900283 T2715 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 900283 T2715 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50158 collection:collection1 shard:shard2
[junit4:junit4] 2> 900284 T2715 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 900289 T2715 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 900292 T2715 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 900292 T2715 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 900292 T2715 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50158/collection1/
[junit4:junit4] 2> 900292 T2715 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 900293 T2715 oasc.SyncStrategy.syncToMe http://127.0.0.1:50158/collection1/ has no replicas
[junit4:junit4] 2> 900293 T2715 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50158/collection1/
[junit4:junit4] 2> 900293 T2715 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 900634 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 900640 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 900641 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 900640 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 900641 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 900649 T2715 oasc.ZkController.register We are http://127.0.0.1:50158/collection1/ and leader is http://127.0.0.1:50158/collection1/
[junit4:junit4] 2> 900650 T2715 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50158
[junit4:junit4] 2> 900650 T2715 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 900650 T2715 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 900650 T2715 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 900652 T2715 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 900653 T2656 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 900654 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 900654 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 900732 T2656 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 900734 T2656 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:42355
[junit4:junit4] 2> 900735 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 900736 T2656 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 900736 T2656 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1372411493192
[junit4:junit4] 2> 900736 T2656 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1372411493192/solr.xml
[junit4:junit4] 2> 900736 T2656 oasc.CoreContainer.<init> New CoreContainer 1997089
[junit4:junit4] 2> 900737 T2656 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1372411493192/'
[junit4:junit4] 2> 900737 T2656 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1372411493192/'
[junit4:junit4] 2> 900791 T2656 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 900792 T2656 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 900792 T2656 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 900792 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 900793 T2656 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 900793 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 900793 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 900793 T2656 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 900794 T2656 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 900794 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 900799 T2656 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 900800 T2656 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43472/solr
[junit4:junit4] 2> 900800 T2656 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 900801 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 900804 T2728 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3811ff8b name:ZooKeeperConnection Watcher:127.0.0.1:43472 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 900805 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 900807 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 900812 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 900813 T2730 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@178d0c99 name:ZooKeeperConnection Watcher:127.0.0.1:43472/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 900814 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 900817 T2656 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 901822 T2656 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42355_
[junit4:junit4] 2> 901823 T2656 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42355_
[junit4:junit4] 2> 901825 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 901826 T2714 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 901827 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 901825 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 901827 T2730 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 901827 T2685 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 901828 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 901829 T2698 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 901829 T2678 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 901833 T2731 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 901833 T2731 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 902146 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 902147 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50158__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50158_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50158"}
[junit4:junit4] 2> 902150 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42355_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42355"}
[junit4:junit4] 2> 902150 T2679 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 902151 T2679 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 902154 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 902154 T2730 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 902154 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 902154 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 902154 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 902835 T2731 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1372411493192/collection1
[junit4:junit4] 2> 902835 T2731 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 902836 T2731 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 902836 T2731 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 902837 T2731 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1372411493192/collection1/'
[junit4:junit4] 2> 902838 T2731 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1372411493192/collection1/lib/README' to classloader
[junit4:junit4] 2> 902838 T2731 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1372411493192/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 902867 T2731 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 902900 T2731 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 902901 T2731 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 902910 T2731 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 903262 T2731 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 903262 T2731 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 903263 T2731 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 903268 T2731 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 903271 T2731 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 903290 T2731 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 903293 T2731 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 903296 T2731 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 903297 T2731 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 903298 T2731 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 903298 T2731 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 903299 T2731 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 903299 T2731 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 903299 T2731 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 903300 T2731 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1372411493192/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty3/
[junit4:junit4] 2> 903300 T2731 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@212dd9fd
[junit4:junit4] 2> 903300 T2731 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 903301 T2731 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty3
[junit4:junit4] 2> 903301 T2731 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty3/index/
[junit4:junit4] 2> 903301 T2731 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 903302 T2731 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty3/index
[junit4:junit4] 2> 903304 T2731 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty3/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 903304 T2731 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 903307 T2731 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 903307 T2731 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 903308 T2731 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 903308 T2731 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 903309 T2731 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 903309 T2731 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 903309 T2731 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 903310 T2731 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 903310 T2731 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 903312 T2731 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 903315 T2731 oass.SolrIndexSearcher.<init> Opening Searcher@ad9385 main
[junit4:junit4] 2> 903315 T2731 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 903315 T2731 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 903321 T2732 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ad9385 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 903324 T2731 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 903325 T2731 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42355 collection:collection1 shard:shard1
[junit4:junit4] 2> 903327 T2731 oasc.ZkController.register We are http://127.0.0.1:42355/collection1/ and leader is http://127.0.0.1:43713/collection1/
[junit4:junit4] 2> 903328 T2731 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42355
[junit4:junit4] 2> 903328 T2731 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 903328 T2731 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C2776 name=collection1 org.apache.solr.core.SolrCore@b04265 url=http://127.0.0.1:42355/collection1 node=127.0.0.1:42355_ C2776_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:42355_, base_url=http://127.0.0.1:42355}
[junit4:junit4] 2> 903329 T2733 C2776 P42355 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 903329 T2733 C2776 P42355 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 903329 T2731 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 903329 T2733 C2776 P42355 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 903330 T2733 C2776 P42355 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 903331 T2656 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 903331 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 903331 T2733 C2776 P42355 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 903332 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 903337 T2691 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:42355__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 903414 T2656 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 903420 T2656 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:48684
[junit4:junit4] 2> 903421 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 903422 T2656 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 903422 T2656 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1372411495869
[junit4:junit4] 2> 903422 T2656 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1372411495869/solr.xml
[junit4:junit4] 2> 903423 T2656 oasc.CoreContainer.<init> New CoreContainer 1458173278
[junit4:junit4] 2> 903423 T2656 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1372411495869/'
[junit4:junit4] 2> 903424 T2656 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1372411495869/'
[junit4:junit4] 2> 903485 T2656 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 903485 T2656 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 903486 T2656 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 903486 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 903486 T2656 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 903487 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 903487 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 903487 T2656 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 903488 T2656 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 903488 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 903492 T2656 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 903493 T2656 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43472/solr
[junit4:junit4] 2> 903493 T2656 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 903494 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 903496 T2745 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a45b380 name:ZooKeeperConnection Watcher:127.0.0.1:43472 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 903496 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 903498 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 903502 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 903504 T2747 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5891874f name:ZooKeeperConnection Watcher:127.0.0.1:43472/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 903504 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 903508 T2656 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 903660 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 903661 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42355__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42355_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42355"}
[junit4:junit4] 2> 903664 T2747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 903664 T2730 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 903665 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 903665 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 903665 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 903664 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 904337 T2691 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:42355__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 904338 T2691 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:42355__collection1&state=recovering&nodeName=127.0.0.1:42355_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1001
[junit4:junit4] 2> 904511 T2656 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48684_
[junit4:junit4] 2> 904513 T2656 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48684_
[junit4:junit4] 2> 904517 T2747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 904517 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 904517 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 904517 T2714 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 904518 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 904518 T2685 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 904518 T2730 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 904518 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 904518 T2730 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 904520 T2698 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 904520 T2747 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 904521 T2678 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 904525 T2748 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 904525 T2748 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 905169 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 905170 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:48684_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:48684"}
[junit4:junit4] 2> 905170 T2679 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 905170 T2679 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 905175 T2747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 905176 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 905176 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 905175 T2730 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 905175 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 905175 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 905527 T2748 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1372411495869/collection1
[junit4:junit4] 2> 905527 T2748 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 905528 T2748 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 905528 T2748 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 905529 T2748 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1372411495869/collection1/'
[junit4:junit4] 2> 905530 T2748 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1372411495869/collection1/lib/README' to classloader
[junit4:junit4] 2> 905530 T2748 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1372411495869/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 905557 T2748 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 905591 T2748 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 905593 T2748 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 905598 T2748 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 905981 T2748 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 905982 T2748 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 905983 T2748 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 905989 T2748 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 905991 T2748 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 906014 T2748 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 906018 T2748 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 906022 T2748 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 906023 T2748 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 906023 T2748 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 906024 T2748 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 906025 T2748 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 906025 T2748 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 906025 T2748 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 906025 T2748 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1372411495869/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty4/
[junit4:junit4] 2> 906026 T2748 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@212dd9fd
[junit4:junit4] 2> 906026 T2748 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 906027 T2748 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty4
[junit4:junit4] 2> 906027 T2748 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty4/index/
[junit4:junit4] 2> 906027 T2748 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 906028 T2748 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty4/index
[junit4:junit4] 2> 906031 T2748 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty4/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 906031 T2748 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 906034 T2748 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 906034 T2748 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 906034 T2748 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 906035 T2748 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 906036 T2748 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 906036 T2748 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 906036 T2748 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 906037 T2748 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 906037 T2748 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 906039 T2748 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 906043 T2748 oass.SolrIndexSearcher.<init> Opening Searcher@4eb5abf1 main
[junit4:junit4] 2> 906044 T2748 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 906044 T2748 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 906052 T2749 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4eb5abf1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 906056 T2748 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 906056 T2748 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48684 collection:collection1 shard:shard2
[junit4:junit4] 2> 906059 T2748 oasc.ZkController.register We are http://127.0.0.1:48684/collection1/ and leader is http://127.0.0.1:50158/collection1/
[junit4:junit4] 2> 906060 T2748 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48684
[junit4:junit4] 2> 906060 T2748 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 906060 T2748 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C2777 name=collection1 org.apache.solr.core.SolrCore@52ed749 url=http://127.0.0.1:48684/collection1 node=127.0.0.1:48684_ C2777_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:48684_, base_url=http://127.0.0.1:48684}
[junit4:junit4] 2> 906061 T2750 C2777 P48684 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 906062 T2748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 906062 T2750 C2777 P48684 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 906062 T2750 C2777 P48684 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 906062 T2750 C2777 P48684 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 906063 T2656 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 906064 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 906064 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 906079 T2750 C2777 P48684 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 906083 T2708 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:48684__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 906152 T2656 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 906159 T2656 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:43468
[junit4:junit4] 2> 906160 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 906161 T2656 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 906161 T2656 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty5-1372411498602
[junit4:junit4] 2> 906161 T2656 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty5-1372411498602/solr.xml
[junit4:junit4] 2> 906161 T2656 oasc.CoreContainer.<init> New CoreContainer 1699032630
[junit4:junit4] 2> 906162 T2656 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty5-1372411498602/'
[junit4:junit4] 2> 906162 T2656 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty5-1372411498602/'
[junit4:junit4] 2> 906215 T2656 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 906215 T2656 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 906216 T2656 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 906216 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 906216 T2656 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 906217 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 906217 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 906218 T2656 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 906218 T2656 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 906218 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 906232 T2656 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 906234 T2656 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43472/solr
[junit4:junit4] 2> 906234 T2656 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 906238 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 906239 T2762 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@682e4a1b name:ZooKeeperConnection Watcher:127.0.0.1:43472 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 906239 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 906242 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 906260 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 906263 T2764 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a8042e5 name:ZooKeeperConnection Watcher:127.0.0.1:43472/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 906263 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 906268 T2656 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C2778 name=collection1 org.apache.solr.core.SolrCore@b04265 url=http://127.0.0.1:42355/collection1 node=127.0.0.1:42355_ C2778_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:42355_, base_url=http://127.0.0.1:42355}
[junit4:junit4] 2> 906339 T2733 C2778 P42355 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:43713/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> ASYNC NEW_CORE C2779 name=collection1 org.apache.solr.core.SolrCore@b04265 url=http://127.0.0.1:42355/collection1 node=127.0.0.1:42355_ C2779_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:42355_, base_url=http://127.0.0.1:42355}
[junit4:junit4] 2> 906352 T2733 C2779 P42355 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:42355 START replicas=[http://127.0.0.1:43713/collection1/] nUpdates=100
[junit4:junit4] 2> 906353 T2733 C2779 P42355 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 906355 T2733 C2779 P42355 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 906355 T2733 C2779 P42355 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 906356 T2733 C2779 P42355 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 906356 T2733 C2779 P42355 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 906356 T2733 C2779 P42355 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:43713/collection1/. core=collection1
[junit4:junit4] 2> 906356 T2733 C2779 P42355 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C2780 name=collection1 org.apache.solr.core.SolrCore@56f1acc3 url=http://127.0.0.1:43713/collection1 node=127.0.0.1:43713_ C2780_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:43713_, base_url=http://127.0.0.1:43713, leader=true}
[junit4:junit4] 2> 906367 T2694 C2780 P43713 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 906370 T2693 C2780 P43713 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 906373 T2693 C2780 P43713 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty1/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 906373 T2693 C2780 P43713 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 906374 T2693 C2780 P43713 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 906374 T2693 C2780 P43713 oass.SolrIndexSearcher.<init> Opening Searcher@70112324 realtime
[junit4:junit4] 2> 906374 T2693 C2780 P43713 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 906375 T2693 C2780 P43713 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 5
[junit4:junit4] 2> 906376 T2733 C2779 P42355 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 906376 T2733 C2779 P42355 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 906380 T2692 C2780 P43713 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 906380 T2692 C2780 P43713 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=3
[junit4:junit4] 2> 906381 T2733 C2779 P42355 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 906381 T2733 C2779 P42355 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 906381 T2733 C2779 P42355 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 906381 T2733 C2779 P42355 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 906382 T2733 C2779 P42355 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 906681 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 906682 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:48684__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:48684_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:48684"}
[junit4:junit4] 2> 906686 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42355__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42355_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42355"}
[junit4:junit4] 2> 906691 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 906691 T2747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 906692 T2764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 906692 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 906692 T2730 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 906693 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 906695 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 907083 T2708 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:48684__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 907084 T2708 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:48684__collection1&state=recovering&nodeName=127.0.0.1:48684_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1001
[junit4:junit4] 2> 907272 T2656 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43468_
[junit4:junit4] 2> 907274 T2656 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43468_
[junit4:junit4] 2> 907276 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 907276 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 907276 T2747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 907277 T2714 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 907277 T2685 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 907277 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 907277 T2730 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 907277 T2730 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 907277 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 907278 T2698 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 907278 T2678 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 907278 T2764 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 907279 T2764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 907279 T2747 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 907285 T2766 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 907286 T2766 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 908205 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 908206 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:43468_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:43468"}
[junit4:junit4] 2> 908206 T2679 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 908206 T2679 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 908210 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 908211 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 908211 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 908211 T2730 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 908211 T2747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 908210 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 908211 T2764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 908287 T2766 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty5-1372411498602/collection1
[junit4:junit4] 2> 908288 T2766 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 908288 T2766 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 908289 T2766 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 908290 T2766 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty5-1372411498602/collection1/'
[junit4:junit4] 2> 908290 T2766 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty5-1372411498602/collection1/lib/README' to classloader
[junit4:junit4] 2> 908290 T2766 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty5-1372411498602/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 908323 T2766 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 908361 T2766 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 908362 T2766 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 908368 T2766 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 908758 T2766 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 908759 T2766 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 908760 T2766 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 908767 T2766 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 908770 T2766 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 908786 T2766 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 908790 T2766 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 908798 T2766 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 908799 T2766 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 908800 T2766 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 908801 T2766 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 908802 T2766 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 908803 T2766 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 908803 T2766 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 908804 T2766 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty5-1372411498602/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty5/
[junit4:junit4] 2> 908804 T2766 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@212dd9fd
[junit4:junit4] 2> 908805 T2766 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 908806 T2766 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty5
[junit4:junit4] 2> 908806 T2766 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty5/index/
[junit4:junit4] 2> 908807 T2766 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty5/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 908807 T2766 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty5/index
[junit4:junit4] 2> 908810 T2766 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty5/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 908811 T2766 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 908814 T2766 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 908815 T2766 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 908815 T2766 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 908816 T2766 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 908816 T2766 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 908816 T2766 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 908817 T2766 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 908817 T2766 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 908817 T2766 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 908819 T2766 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 908822 T2766 oass.SolrIndexSearcher.<init> Opening Searcher@353669a5 main
[junit4:junit4] 2> 908822 T2766 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 908822 T2766 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 908827 T2767 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@353669a5 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 908830 T2766 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 908830 T2766 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43468 collection:collection1 shard:shard1
[junit4:junit4] 2> 908834 T2766 oasc.ZkController.register We are http://127.0.0.1:43468/collection1/ and leader is http://127.0.0.1:43713/collection1/
[junit4:junit4] 2> 908834 T2766 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43468
[junit4:junit4] 2> 908834 T2766 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 908834 T2766 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C2781 name=collection1 org.apache.solr.core.SolrCore@1d6f125a url=http://127.0.0.1:43468/collection1 node=127.0.0.1:43468_ C2781_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:43468_, base_url=http://127.0.0.1:43468}
[junit4:junit4] 2> 908835 T2768 C2781 P43468 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 908835 T2766 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 908836 T2768 C2781 P43468 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 908837 T2768 C2781 P43468 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 908837 T2768 C2781 P43468 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 908840 T2768 C2781 P43468 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 908843 T2656 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 908843 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 908844 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 908844 T2693 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:43468__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 908924 T2656 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 908936 T2656 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:43667
[junit4:junit4] 2> 908937 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 908937 T2656 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 908937 T2656 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty6-1372411501381
[junit4:junit4] 2> 908938 T2656 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty6-1372411501381/solr.xml
[junit4:junit4] 2> 908938 T2656 oasc.CoreContainer.<init> New CoreContainer 874849653
[junit4:junit4] 2> 908938 T2656 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty6-1372411501381/'
[junit4:junit4] 2> 908939 T2656 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty6-1372411501381/'
[junit4:junit4] 2> 908989 T2656 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 908989 T2656 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 908990 T2656 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 908990 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 908990 T2656 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 908990 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 908991 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 908991 T2656 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 908991 T2656 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 908992 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 908995 T2656 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 908996 T2656 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43472/solr
[junit4:junit4] 2> 908996 T2656 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 908997 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 909005 T2780 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6099b659 name:ZooKeeperConnection Watcher:127.0.0.1:43472 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 909006 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 909008 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 909012 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 909018 T2782 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78969649 name:ZooKeeperConnection Watcher:127.0.0.1:43472/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 909018 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 909022 T2656 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C2782 name=collection1 org.apache.solr.core.SolrCore@52ed749 url=http://127.0.0.1:48684/collection1 node=127.0.0.1:48684_ C2782_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:48684_, base_url=http://127.0.0.1:48684}
[junit4:junit4] 2> 909085 T2750 C2782 P48684 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50158/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 909085 T2750 C2782 P48684 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:48684 START replicas=[http://127.0.0.1:50158/collection1/] nUpdates=100
[junit4:junit4] 2> 909086 T2750 C2782 P48684 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 909086 T2750 C2782 P48684 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 909086 T2750 C2782 P48684 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 909086 T2750 C2782 P48684 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 909086 T2750 C2782 P48684 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 909087 T2750 C2782 P48684 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:50158/collection1/. core=collection1
[junit4:junit4] 2> 909087 T2750 C2782 P48684 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C2783 name=collection1 org.apache.solr.core.SolrCore@6e033e1f url=http://127.0.0.1:50158/collection1 node=127.0.0.1:50158_ C2783_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:50158_, base_url=http://127.0.0.1:50158, leader=true}
[junit4:junit4] 2> 909094 T2710 C2783 P50158 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 909096 T2708 C2783 P50158 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 909100 T2708 C2783 P50158 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty2/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 909101 T2708 C2783 P50158 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 909102 T2708 C2783 P50158 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 909102 T2708 C2783 P50158 oass.SolrIndexSearcher.<init> Opening Searcher@edaed19 realtime
[junit4:junit4] 2> 909103 T2708 C2783 P50158 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 909103 T2708 C2783 P50158 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 7
[junit4:junit4] 2> 909104 T2750 C2782 P48684 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 909105 T2750 C2782 P48684 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 909107 T2707 C2783 P50158 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 909107 T2707 C2783 P50158 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 909108 T2750 C2782 P48684 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 909109 T2750 C2782 P48684 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 909109 T2750 C2782 P48684 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 909109 T2750 C2782 P48684 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 909110 T2750 C2782 P48684 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 909723 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 909724 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:43468__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:43468_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:43468"}
[junit4:junit4] 2> 909727 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:48684__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:48684_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:48684"}
[junit4:junit4] 2> 909733 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 909733 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 909733 T2730 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 909733 T2764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 909733 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 909733 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 909733 T2747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 909733 T2782 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 909844 T2693 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:43468__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 909845 T2693 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:43468__collection1&state=recovering&nodeName=127.0.0.1:43468_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1001
[junit4:junit4] 2> 910026 T2656 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43667_
[junit4:junit4] 2> 910027 T2656 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43667_
[junit4:junit4] 2> 910029 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 910029 T2747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 910030 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 910030 T2730 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 910030 T2730 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 910030 T2714 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 910031 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 910031 T2685 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 910031 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 910031 T2764 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 910032 T2764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 910032 T2782 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 910032 T2782 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 910034 T2698 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 910035 T2678 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 910035 T2747 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 910041 T2784 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 910043 T2784 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 911243 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 911244 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:43667_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:43667"}
[junit4:junit4] 2> 911244 T2679 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 911244 T2679 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 911249 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 911249 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 911249 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 911249 T2782 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 911249 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 911249 T2747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 911249 T2764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 911249 T2730 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> ASYNC NEW_CORE C2784 name=collection1 org.apache.solr.core.SolrCore@1d6f125a url=http://127.0.0.1:43468/collection1 node=127.0.0.1:43468_ C2784_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:43468_, base_url=http://127.0.0.1:43468}
[junit4:junit4] 2> 911845 T2768 C2784 P43468 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:43713/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 911846 T2768 C2784 P43468 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:43468 START replicas=[http://127.0.0.1:43713/collection1/] nUpdates=100
[junit4:junit4] 2> 911846 T2768 C2784 P43468 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 911847 T2768 C2784 P43468 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 911847 T2768 C2784 P43468 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 911847 T2768 C2784 P43468 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 911847 T2768 C2784 P43468 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 911848 T2768 C2784 P43468 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:43713/collection1/. core=collection1
[junit4:junit4] 2> 911848 T2768 C2784 P43468 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C2785 name=collection1 org.apache.solr.core.SolrCore@56f1acc3 url=http://127.0.0.1:43713/collection1 node=127.0.0.1:43713_ C2785_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:43713_, base_url=http://127.0.0.1:43713, leader=true}
[junit4:junit4] 2> 911849 T2694 C2785 P43713 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 911853 T2692 C2785 P43713 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 911853 T2692 C2785 P43713 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 911854 T2692 C2785 P43713 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 911854 T2692 C2785 P43713 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 2
[junit4:junit4] 2> 911855 T2768 C2784 P43468 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 911855 T2768 C2784 P43468 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 911859 T2691 C2785 P43713 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 911860 T2768 C2784 P43468 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 911860 T2768 C2784 P43468 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 911860 T2768 C2784 P43468 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 911860 T2768 C2784 P43468 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 911862 T2768 C2784 P43468 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 912045 T2784 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty6-1372411501381/collection1
[junit4:junit4] 2> 912045 T2784 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 912046 T2784 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 912046 T2784 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 912047 T2784 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty6-1372411501381/collection1/'
[junit4:junit4] 2> 912048 T2784 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty6-1372411501381/collection1/lib/README' to classloader
[junit4:junit4] 2> 912048 T2784 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty6-1372411501381/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 912085 T2784 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 912127 T2784 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 912129 T2784 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 912133 T2784 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 912499 T2784 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 912499 T2784 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 912500 T2784 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 912505 T2784 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 912507 T2784 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 912520 T2784 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 912524 T2784 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 912527 T2784 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 912528 T2784 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 912529 T2784 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 912529 T2784 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 912530 T2784 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 912531 T2784 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 912531 T2784 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 912531 T2784 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty6-1372411501381/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty6/
[junit4:junit4] 2> 912531 T2784 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@212dd9fd
[junit4:junit4] 2> 912532 T2784 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 912532 T2784 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty6
[junit4:junit4] 2> 912532 T2784 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty6/index/
[junit4:junit4] 2> 912533 T2784 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty6/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 912533 T2784 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty6/index
[junit4:junit4] 2> 912539 T2784 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty6/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 912539 T2784 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 912542 T2784 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 912543 T2784 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 912543 T2784 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 912544 T2784 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 912544 T2784 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 912544 T2784 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 912546 T2784 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 912546 T2784 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 912547 T2784 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 912549 T2784 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 912552 T2784 oass.SolrIndexSearcher.<init> Opening Searcher@157cc29a main
[junit4:junit4] 2> 912552 T2784 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 912552 T2784 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 912558 T2786 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@157cc29a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 912561 T2784 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 912561 T2784 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43667 collection:collection1 shard:shard2
[junit4:junit4] 2> 912564 T2784 oasc.ZkController.register We are http://127.0.0.1:43667/collection1/ and leader is http://127.0.0.1:50158/collection1/
[junit4:junit4] 2> 912565 T2784 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43667
[junit4:junit4] 2> 912565 T2784 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 912565 T2784 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C2786 name=collection1 org.apache.solr.core.SolrCore@26912e77 url=http://127.0.0.1:43667/collection1 node=127.0.0.1:43667_ C2786_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:43667_, base_url=http://127.0.0.1:43667}
[junit4:junit4] 2> 912568 T2787 C2786 P43667 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 912569 T2787 C2786 P43667 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 912569 T2784 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 912569 T2787 C2786 P43667 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 912570 T2787 C2786 P43667 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 912572 T2787 C2786 P43667 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 912573 T2656 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 912573 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 912573 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 912578 T2709 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:43667__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 912662 T2656 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 912665 T2656 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46286
[junit4:junit4] 2> 912666 T2656 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 912666 T2656 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 912666 T2656 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty7-1372411505111
[junit4:junit4] 2> 912667 T2656 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty7-1372411505111/solr.xml
[junit4:junit4] 2> 912667 T2656 oasc.CoreContainer.<init> New CoreContainer 277790022
[junit4:junit4] 2> 912668 T2656 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty7-1372411505111/'
[junit4:junit4] 2> 912668 T2656 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty7-1372411505111/'
[junit4:junit4] 2> 912711 T2656 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 912711 T2656 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 912712 T2656 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 912712 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 912712 T2656 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 912712 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 912713 T2656 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 912713 T2656 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 912713 T2656 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 912713 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 912717 T2656 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 912717 T2656 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43472/solr
[junit4:junit4] 2> 912718 T2656 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 912719 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 912726 T2799 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@106e3d37 name:ZooKeeperConnection Watcher:127.0.0.1:43472 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 912726 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 912729 T2656 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 912733 T2656 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 912737 T2801 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@65fd7f79 name:ZooKeeperConnection Watcher:127.0.0.1:43472/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 912737 T2656 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 912742 T2656 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 912754 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 912755 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:43468__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:43468_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:43468"}
[junit4:junit4] 2> 912760 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:43667__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:43667_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:43667"}
[junit4:junit4] 2> 912765 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 912765 T2764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 912765 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 912765 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 912765 T2801 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 912765 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 912765 T2730 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 912765 T2747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 912765 T2782 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 913578 T2709 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:43667__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 913579 T2709 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:43667__collection1&state=recovering&nodeName=127.0.0.1:43667_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1001
[junit4:junit4] 2> 913745 T2656 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46286_
[junit4:junit4] 2> 913747 T2656 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46286_
[junit4:junit4] 2> 913748 T2747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 913749 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 913749 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 913749 T2714 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 913750 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 913750 T2685 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 913750 T2730 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 913750 T2801 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 913750 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 913750 T2782 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 913751 T2782 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 913750 T2764 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 913751 T2764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 913751 T2801 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 913750 T2730 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 913752 T2698 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 913752 T2747 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 913753 T2678 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 913757 T2802 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 913758 T2802 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 914279 T2679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 914280 T2679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:46286_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:46286"}
[junit4:junit4] 2> 914280 T2679 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 914281 T2679 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 914284 T2747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 914284 T2801 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 914284 T2730 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 914285 T2764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 914285 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 914285 T2782 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 914285 T2685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 914285 T2698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 914284 T2678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 914760 T2802 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty7-1372411505111/collection1
[junit4:junit4] 2> 914760 T2802 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 914761 T2802 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 914761 T2802 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 914762 T2802 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty7-1372411505111/collection1/'
[junit4:junit4] 2> 914763 T2802 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty7-1372411505111/collection1/lib/README' to classloader
[junit4:junit4] 2> 914763 T2802 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty7-1372411505111/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 914800 T2802 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 914840 T2802 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 914842 T2802 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 914845 T2802 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 915205 T2802 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 915206 T2802 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 915207 T2802 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 915213 T2802 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 915216 T2802 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 915229 T2802 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 915234 T2802 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 915237 T2802 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 915239 T2802 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 915239 T2802 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 915239 T2802 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 915241 T2802 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 915241 T2802 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 915241 T2802 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 915241 T2802 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty7-1372411505111/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty7/
[junit4:junit4] 2> 915241 T2802 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@212dd9fd
[junit4:junit4] 2> 915242 T2802 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 915242 T2802 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty7
[junit4:junit4] 2> 915243 T2802 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty7/index/
[junit4:junit4] 2> 915243 T2802 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty7/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 915243 T2802 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty7/index
[junit4:junit4] 2> 915246 T2802 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty7/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 915246 T2802 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 915249 T2802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 915250 T2802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 915250 T2802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 915251 T2802 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 915252 T2802 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 915252 T2802 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 915253 T2802 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 915253 T2802 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 915254 T2802 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 915256 T2802 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 915260 T2802 oass.SolrIndexSearcher.<init> Opening Searcher@61d42948 main
[junit4:junit4] 2> 915261 T2802 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 915261 T2802 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 915267 T2803 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@61d42948 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 915270 T2802 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 915270 T2802 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:46286 collection:collection1 shard:shard1
[junit4:junit4] 2> 915273 T2802 oasc.ZkController.register We are http://127.0.0.1:46286/collection1/ and leader is http://127.0.0.1:43713/collection1/
[junit4:junit4] 2> 915274 T2802 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:46286
[junit4:junit4] 2> 915274 T2802 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 915274 T2802 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C2787 name=collection1 org.apache.solr.core.SolrCore@58692c7c url=http://127.0.0.1:46286/collection1 node=127.0.0.1:46286_ C2787_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:46286_, base_url=http://127.0.0.1:46286}
[junit4:junit4] 2> 915275 T2804 C2787 P46286 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 915275 T2802 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 915276 T2804 C2787 P46286 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 915276 T2804 C2787 P46286 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 915277 T2804 C2787 P46286 oasc.ZkController.publish numShards not found on descriptor - reading it from system p
[...truncated too long message...]
te.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 1053197 T2656 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 1053198 T2656 oasc.CachingDirectoryFactory.close Closing StandardDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 1053198 T2656 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty7 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty7;done=false>>]
[junit4:junit4] 2> 1053198 T2656 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty7
[junit4:junit4] 2> 1053199 T2656 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty7/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty7/index;done=false>>]
[junit4:junit4] 2> 1053199 T2656 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1372411483701/jetty7/index
[junit4:junit4] 2> 1053200 T3014 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89942358996025362-127.0.0.1:46286_-n_0000000007) am no longer a leader.
[junit4:junit4] 2> 1053223 T2656 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 1053305 T2656 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 1053307 T2656 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:43472 43472
[junit4:junit4] 1> /solr/overseer_elect/election/89942358996025362-127.0.0.1:46286_-n_0000000007 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89942358996025360-127.0.0.1:43667_-n_0000000006 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89942358996025365-127.0.0.1:48684_-n_0000000010 (0)
[junit4:junit4] 1> /solr/overseer_elect/leader (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"id":"89942358996025347-127.0.0.1:40775_-n_0000000000"}
[junit4:junit4] 1> /zookeeper (1)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeyNothingIsSafeTest -Dtests.method=testDistribSearch -Dtests.seed=E7BEBAEF4DB0C807 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ja_JP -Dtests.timezone=Asia/Colombo -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] FAILURE 162s J1 | ChaosMonkeyNothingIsSafeTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: shard1 is not consistent. Got 188 from http://127.0.0.1:43713/collection1lastClient and got 187 from http://127.0.0.1:42355/collection1
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([E7BEBAEF4DB0C807:665834F73AEFA83B]:0)
[junit4:junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1018)
[junit4:junit4] > at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.java:194)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4:junit4] 2> 1053318 T2656 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 162161 T2655 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4:junit4] 2> 1053414 T2782 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1053415 T2782 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 1053415 T2782 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1054501 T2801 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1054502 T2801 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 1054502 T2801 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> NOTE: test params are: codec=Lucene3x, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=ja_JP, timezone=Asia/Colombo
[junit4:junit4] 2> NOTE: Linux 3.2.0-48-generic amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=8,threads=2,free=205218216,total=388583424
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestSchemaVersionResource, SampleTest, OpenCloseCoreStressTest, TestOmitPositions, FieldAnalysisRequestHandlerTest, TestCSVLoader, TestSolrXMLSerializer, NumericFieldsTest, TestRangeQuery, TestElisionMultitermQuery, SpellCheckCollatorTest, LeaderElectionIntegrationTest, FileUtilsTest, BasicDistributedZk2Test, UpdateParamsTest, CopyFieldTest, DistanceFunctionTest, ZkSolrClientTest, OutputWriterTest, ConvertedLegacyTest, IndexSchemaRuntimeFieldTest, TestSchemaResource, ClusterStateTest, TestQuerySenderNoQuery, TestIndexingPerformance, ZkNodePropsTest, IndexBasedSpellCheckerTest, TestStressLucene, TestPartialUpdateDeduplication, StatsComponentTest, XmlUpdateRequestHandlerTest, CollectionsAPIDistributedZkTest, TestSerializedLuceneMatchVersion, TestArbitraryIndexDir, SolrRequestParserTest, TestFastOutputStream, SortByFunctionTest, BadIndexSchemaTest, TestIndexSearcher, TestDistributedGrouping, NoCacheHeaderTest, TestAtomicUpdateErrorCases, IndexReaderFactoryTest, DocumentAnalysisRequestHandlerTest, TestSolr4Spatial, HighlighterConfigTest, DateMathParserTest, TestCollationField, TestReload, HardAutoCommitTest, TestMergePolicyConfig, TestSchemaSimilarityResource, TestQueryTypes, TestFieldCollectionResource, PathHierarchyTokenizerFactoryTest, TestManagedSchema, TestBM25SimilarityFactory, HighlighterTest, TestDistributedSearch, SolrIndexConfigTest, NotRequiredUniqueKeyTest, EchoParamsTest, SuggesterTSTTest, BasicZkTest, TestRecovery, TestCoreDiscovery, TestZkChroot, TestDefaultSimilarityFactory, ShardSplitTest, TestAnalyzedSuggestions, ChaosMonkeySafeLeaderTest, TestRandomFaceting, TestMultiCoreConfBootstrap, TestStressVersions, SpellCheckComponentTest, SolrCmdDistributorTest, TestSort, TestFunctionQuery, TestLazyCores, DirectUpdateHandlerTest, TestBadConfig, SoftAutoCommitTest, DistributedQueryElevationComponentTest, CurrencyFieldXmlFileTest, SignatureUpdateProcessorFactoryTest, SuggesterFSTTest, TestFoldingMultitermQuery, SuggesterTest, TestTrie, WordBreakSolrSpellCheckerTest, SolrCoreCheckLockOnStartupTest, TestUpdate, TestWordDelimiterFilterFactory, DefaultValueUpdateProcessorTest, TestRemoteStreaming, DocValuesMultiTest, XsltUpdateRequestHandlerTest, DebugComponentTest, TestSurroundQueryParser, LukeRequestHandlerTest, DisMaxRequestHandlerTest, TestWriterPerf, TestReversedWildcardFilterFactory, MoreLikeThisHandlerTest, FastVectorHighlighterTest, SolrPluginUtilsTest, ReturnFieldsTest, JSONWriterTest, MBeansHandlerTest, UniqFieldsUpdateProcessorFactoryTest, TestPHPSerializedResponseWriter, CSVRequestHandlerTest, CoreContainerCoreInitFailuresTest, TestPropInject, TestQuerySenderListener, ResponseLogComponentTest, TestSolrDeletionPolicy2, MultiTermTest, TestBinaryField, TestSearchPerf, TestConfig, TestSolrCoreProperties, TestPostingsSolrHighlighter, DirectSolrConnectionTest, TestLuceneMatchVersion, TestPhraseSuggestions, SpellPossibilityIteratorTest, TestCodecSupport, SynonymTokenizerTest, TestDFRSimilarityFactory, TestPerFieldSimilarity, TestNumberUtils, TestLMJelinekMercerSimilarityFactory, TestIBSimilarityFactory, LegacyHTMLStripCharFilterTest, TestJmxMonitoredMap, TestPluginEnable, TimeZoneUtilsTest, ResourceLoaderTest, ScriptEngineTest, OpenExchangeRatesOrgProviderTest, URLClassifyProcessorTest, TestFastLRUCache, ChaosMonkeyNothingIsSafeTest]
[junit4:junit4] Completed on J1 in 163.44s, 1 test, 1 failure <<< FAILURES!
[...truncated 10 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:392: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:372: 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/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:437: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1248: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:892: There were test failures: 299 suites, 1290 tests, 1 failure, 15 ignored (6 assumptions)
Total time: 36 minutes 39 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0-ea-b94 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure