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/01 14:44:24 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.7.0_21) - Build # 5868
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/5868/
Java: 64bit/jdk1.7.0_21 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
shard1 is not consistent. Got 224 from http://127.0.0.1:58725/_e/gd/collection1lastClient and got 217 from http://127.0.0.1:47978/_e/gd/collection1
Stack Trace:
java.lang.AssertionError: shard1 is not consistent. Got 224 from http://127.0.0.1:58725/_e/gd/collection1lastClient and got 217 from http://127.0.0.1:47978/_e/gd/collection1
at __randomizedtesting.SeedInfo.seed([F5AC56AF1C458EB1:744AD8B76B1AEE8D]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:963)
at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:137)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
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:601)
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:722)
Build Log:
[...truncated 9481 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4:junit4] 2> 217684 T958 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_e/gd
[junit4:junit4] 2> 217689 T958 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-ChaosMonkeySafeLeaderTest-1370089576954
[junit4:junit4] 2> 217690 T958 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 217690 T959 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 217790 T958 oasc.ZkTestServer.run start zk server on port:36904
[junit4:junit4] 2> 217791 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 217873 T965 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4248b178 name:ZooKeeperConnection Watcher:127.0.0.1:36904 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 217873 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 217873 T958 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 217878 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 217880 T967 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e85e1c7 name:ZooKeeperConnection Watcher:127.0.0.1:36904/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 217880 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 217880 T958 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 217883 T958 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 217885 T958 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 217887 T958 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 217889 T958 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> 217890 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 217893 T958 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> 217894 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 217897 T958 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> 217897 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 217899 T958 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> 217900 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 217902 T958 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> 217903 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 217905 T958 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> 217906 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 217908 T958 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> 217909 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 217911 T958 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> 217912 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 217915 T958 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> 217916 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 217989 T958 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 217992 T958 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46693
[junit4:junit4] 2> 217992 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 217993 T958 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 217993 T958 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.ChaosMonkeySafeLeaderTest-controljetty-1370089577184
[junit4:junit4] 2> 217993 T958 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.ChaosMonkeySafeLeaderTest-controljetty-1370089577184/solr.xml
[junit4:junit4] 2> 217994 T958 oasc.CoreContainer.<init> New CoreContainer 1631499304
[junit4:junit4] 2> 217994 T958 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.ChaosMonkeySafeLeaderTest-controljetty-1370089577184/'
[junit4:junit4] 2> 217994 T958 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.ChaosMonkeySafeLeaderTest-controljetty-1370089577184/'
[junit4:junit4] 2> 218041 T958 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 218042 T958 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 218042 T958 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 218042 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 218043 T958 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 218043 T958 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 218044 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 218044 T958 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 218044 T958 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 218045 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 218048 T958 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 218049 T958 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36904/solr
[junit4:junit4] 2> 218049 T958 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 218050 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 218051 T978 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@775ed0b4 name:ZooKeeperConnection Watcher:127.0.0.1:36904 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 218052 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 218053 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 218057 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 218058 T980 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1aeb743 name:ZooKeeperConnection Watcher:127.0.0.1:36904/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 218058 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 218060 T958 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 218063 T958 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 218066 T958 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 218068 T958 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46693__e%2Fgd
[junit4:junit4] 2> 218069 T958 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46693__e%2Fgd
[junit4:junit4] 2> 218072 T958 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 218077 T958 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 218079 T958 oasc.Overseer.start Overseer (id=89790190515453955-127.0.0.1:46693__e%2Fgd-n_0000000000) starting
[junit4:junit4] 2> 218082 T958 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 218085 T982 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 218085 T958 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 218088 T958 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 218091 T958 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 218096 T981 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 218098 T983 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.ChaosMonkeySafeLeaderTest-controljetty-1370089577184/collection1
[junit4:junit4] 2> 218099 T983 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 218100 T983 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 218100 T983 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 218101 T983 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.ChaosMonkeySafeLeaderTest-controljetty-1370089577184/collection1/'
[junit4:junit4] 2> 218101 T983 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1370089577184/collection1/lib/README' to classloader
[junit4:junit4] 2> 218102 T983 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1370089577184/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 218134 T983 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 218164 T983 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 218166 T983 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 218170 T983 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 218481 T983 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 218486 T983 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 218488 T983 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 218502 T983 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 218505 T983 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 218507 T983 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 218508 T983 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 218508 T983 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 218508 T983 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 218509 T983 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 218510 T983 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 218510 T983 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 218518 T983 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.ChaosMonkeySafeLeaderTest-controljetty-1370089577184/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/control/data/
[junit4:junit4] 2> 218518 T983 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e24d5d8
[junit4:junit4] 2> 218518 T983 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 218519 T983 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.ChaosMonkeySafeLeaderTest-1370089576954/control/data
[junit4:junit4] 2> 218519 T983 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/control/data/index/
[junit4:junit4] 2> 218519 T983 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 218519 T983 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.ChaosMonkeySafeLeaderTest-1370089576954/control/data/index
[junit4:junit4] 2> 218522 T983 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.ChaosMonkeySafeLeaderTest-1370089576954/control/data/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 218522 T983 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 218524 T983 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 218524 T983 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 218525 T983 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 218525 T983 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 218526 T983 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 218526 T983 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 218526 T983 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 218526 T983 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 218527 T983 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 218529 T983 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 218531 T983 oass.SolrIndexSearcher.<init> Opening Searcher@5cfdbc1b main
[junit4:junit4] 2> 218532 T983 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 218532 T983 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 218535 T984 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5cfdbc1b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 218535 T983 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 218535 T983 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 219601 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 219602 T981 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:46693__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:46693/_e/gd"}
[junit4:junit4] 2> 219602 T981 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 219602 T981 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 219608 T980 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> 220537 T983 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 220537 T983 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:46693/_e/gd collection:control_collection shard:shard1
[junit4:junit4] 2> 220539 T983 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 220551 T983 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 220555 T983 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 220556 T983 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 220556 T983 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:46693/_e/gd/collection1/
[junit4:junit4] 2> 220556 T983 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 220557 T983 oasc.SyncStrategy.syncToMe http://127.0.0.1:46693/_e/gd/collection1/ has no replicas
[junit4:junit4] 2> 220557 T983 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:46693/_e/gd/collection1/
[junit4:junit4] 2> 220557 T983 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 221115 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 221128 T980 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> 221166 T983 oasc.ZkController.register We are http://127.0.0.1:46693/_e/gd/collection1/ and leader is http://127.0.0.1:46693/_e/gd/collection1/
[junit4:junit4] 2> 221167 T983 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:46693/_e/gd
[junit4:junit4] 2> 221167 T983 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 221167 T983 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 221167 T983 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 221168 T983 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 221169 T958 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 221170 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 221170 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 221176 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 221176 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 221178 T987 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@72862c8b name:ZooKeeperConnection Watcher:127.0.0.1:36904/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 221178 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 221179 T958 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 221181 T958 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 221247 T958 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 221249 T958 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58725
[junit4:junit4] 2> 221250 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 221250 T958 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 221250 T958 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.ChaosMonkeySafeLeaderTest-jetty1-1370089580447
[junit4:junit4] 2> 221251 T958 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.ChaosMonkeySafeLeaderTest-jetty1-1370089580447/solr.xml
[junit4:junit4] 2> 221251 T958 oasc.CoreContainer.<init> New CoreContainer 110047471
[junit4:junit4] 2> 221251 T958 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.ChaosMonkeySafeLeaderTest-jetty1-1370089580447/'
[junit4:junit4] 2> 221252 T958 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.ChaosMonkeySafeLeaderTest-jetty1-1370089580447/'
[junit4:junit4] 2> 221294 T958 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 221295 T958 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 221295 T958 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 221295 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 221296 T958 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 221296 T958 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 221296 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 221296 T958 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 221297 T958 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 221297 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 221301 T958 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 221301 T958 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36904/solr
[junit4:junit4] 2> 221301 T958 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 221302 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 221303 T998 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15e01b22 name:ZooKeeperConnection Watcher:127.0.0.1:36904 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 221304 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 221305 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 221308 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 221310 T1000 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78e484d2 name:ZooKeeperConnection Watcher:127.0.0.1:36904/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 221310 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 221313 T958 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 222316 T958 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58725__e%2Fgd
[junit4:junit4] 2> 222317 T958 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58725__e%2Fgd
[junit4:junit4] 2> 222321 T987 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 222321 T1000 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 222321 T980 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 222322 T980 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> 222328 T1001 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.ChaosMonkeySafeLeaderTest-jetty1-1370089580447/collection1
[junit4:junit4] 2> 222328 T1001 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 222329 T1001 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 222329 T1001 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 222330 T1001 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.ChaosMonkeySafeLeaderTest-jetty1-1370089580447/collection1/'
[junit4:junit4] 2> 222331 T1001 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1370089580447/collection1/lib/README' to classloader
[junit4:junit4] 2> 222331 T1001 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1370089580447/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 222364 T1001 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 222392 T1001 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 222394 T1001 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 222397 T1001 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 222635 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 222636 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:46693__e%2Fgd_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:46693__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:46693/_e/gd"}
[junit4:junit4] 2> 222639 T987 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> 222639 T1000 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> 222639 T980 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> 222702 T1001 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 222707 T1001 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 222709 T1001 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 222721 T1001 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 222724 T1001 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 222727 T1001 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 222728 T1001 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 222729 T1001 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 222729 T1001 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 222730 T1001 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 222730 T1001 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 222730 T1001 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 222730 T1001 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.ChaosMonkeySafeLeaderTest-jetty1-1370089580447/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty1/
[junit4:junit4] 2> 222731 T1001 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e24d5d8
[junit4:junit4] 2> 222731 T1001 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 222732 T1001 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty1
[junit4:junit4] 2> 222732 T1001 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty1/index/
[junit4:junit4] 2> 222732 T1001 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 222732 T1001 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty1/index
[junit4:junit4] 2> 222735 T1001 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty1/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 222735 T1001 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 222737 T1001 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 222737 T1001 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 222738 T1001 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 222738 T1001 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 222739 T1001 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 222739 T1001 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 222739 T1001 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 222740 T1001 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 222740 T1001 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 222742 T1001 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 222745 T1001 oass.SolrIndexSearcher.<init> Opening Searcher@1d4b615e main
[junit4:junit4] 2> 222746 T1001 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 222746 T1001 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 222750 T1002 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1d4b615e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 222752 T1001 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 222752 T1001 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 224143 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 224144 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"3",
[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:58725__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58725/_e/gd"}
[junit4:junit4] 2> 224144 T981 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 3
[junit4:junit4] 2> 224144 T981 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 224148 T980 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> 224148 T1000 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> 224148 T987 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> 224754 T1001 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 224754 T1001 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58725/_e/gd collection:collection1 shard:shard1
[junit4:junit4] 2> 224756 T1001 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 224766 T1001 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 224770 T1001 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 224771 T1001 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 224771 T1001 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58725/_e/gd/collection1/
[junit4:junit4] 2> 224771 T1001 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 224772 T1001 oasc.SyncStrategy.syncToMe http://127.0.0.1:58725/_e/gd/collection1/ has no replicas
[junit4:junit4] 2> 224772 T1001 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58725/_e/gd/collection1/
[junit4:junit4] 2> 224772 T1001 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 225654 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 225667 T987 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> 225667 T1000 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> 225667 T980 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> 225685 T1001 oasc.ZkController.register We are http://127.0.0.1:58725/_e/gd/collection1/ and leader is http://127.0.0.1:58725/_e/gd/collection1/
[junit4:junit4] 2> 225685 T1001 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58725/_e/gd
[junit4:junit4] 2> 225685 T1001 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 225686 T1001 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 225686 T1001 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 225689 T1001 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 225690 T958 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 225691 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 225692 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 225761 T958 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 225764 T958 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60810
[junit4:junit4] 2> 225765 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 225765 T958 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 225765 T958 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.ChaosMonkeySafeLeaderTest-jetty2-1370089584963
[junit4:junit4] 2> 225766 T958 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.ChaosMonkeySafeLeaderTest-jetty2-1370089584963/solr.xml
[junit4:junit4] 2> 225766 T958 oasc.CoreContainer.<init> New CoreContainer 398036611
[junit4:junit4] 2> 225766 T958 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.ChaosMonkeySafeLeaderTest-jetty2-1370089584963/'
[junit4:junit4] 2> 225767 T958 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.ChaosMonkeySafeLeaderTest-jetty2-1370089584963/'
[junit4:junit4] 2> 225806 T958 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 225806 T958 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 225807 T958 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 225807 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 225807 T958 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 225808 T958 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 225808 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 225808 T958 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 225808 T958 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 225809 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 225812 T958 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 225812 T958 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36904/solr
[junit4:junit4] 2> 225813 T958 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 225814 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 225815 T1014 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e5bf89c name:ZooKeeperConnection Watcher:127.0.0.1:36904 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 225816 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 225818 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 225821 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 225823 T1016 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@27f88b13 name:ZooKeeperConnection Watcher:127.0.0.1:36904/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 225823 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 225827 T958 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 226829 T958 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60810__e%2Fgd
[junit4:junit4] 2> 226831 T958 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60810__e%2Fgd
[junit4:junit4] 2> 226833 T1000 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> 226836 T987 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 226836 T980 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 226837 T980 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> 226836 T987 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> 226837 T1016 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 226838 T1000 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 226842 T1017 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.ChaosMonkeySafeLeaderTest-jetty2-1370089584963/collection1
[junit4:junit4] 2> 226842 T1017 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 226843 T1017 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 226843 T1017 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 226844 T1017 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.ChaosMonkeySafeLeaderTest-jetty2-1370089584963/collection1/'
[junit4:junit4] 2> 226845 T1017 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1370089584963/collection1/lib/README' to classloader
[junit4:junit4] 2> 226845 T1017 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1370089584963/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 226868 T1017 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 226896 T1017 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 226909 T1017 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 226913 T1017 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 227175 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 227176 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:58725__e%2Fgd_collection1",
[junit4:junit4] 2> "numShards":"3",
[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:58725__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58725/_e/gd"}
[junit4:junit4] 2> 227179 T987 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> 227179 T1000 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> 227179 T1016 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> 227179 T980 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> 227229 T1017 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 227235 T1017 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 227237 T1017 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 227249 T1017 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 227252 T1017 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 227255 T1017 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 227256 T1017 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 227256 T1017 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 227256 T1017 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 227257 T1017 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 227257 T1017 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 227258 T1017 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 227258 T1017 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.ChaosMonkeySafeLeaderTest-jetty2-1370089584963/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty2/
[junit4:junit4] 2> 227258 T1017 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e24d5d8
[junit4:junit4] 2> 227259 T1017 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 227259 T1017 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty2
[junit4:junit4] 2> 227259 T1017 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty2/index/
[junit4:junit4] 2> 227259 T1017 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 227260 T1017 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty2/index
[junit4:junit4] 2> 227262 T1017 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty2/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 227263 T1017 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 227264 T1017 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 227265 T1017 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 227265 T1017 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 227266 T1017 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 227266 T1017 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 227266 T1017 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 227266 T1017 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 227267 T1017 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 227267 T1017 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 227269 T1017 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 227272 T1017 oass.SolrIndexSearcher.<init> Opening Searcher@7a045538 main
[junit4:junit4] 2> 227273 T1017 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 227273 T1017 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 227276 T1018 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7a045538 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 227278 T1017 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 227278 T1017 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 228686 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 228687 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"3",
[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:60810__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:60810/_e/gd"}
[junit4:junit4] 2> 228687 T981 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 228687 T981 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 228692 T987 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> 228692 T1016 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> 228692 T1000 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> 228692 T980 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> 229280 T1017 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 229281 T1017 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60810/_e/gd collection:collection1 shard:shard2
[junit4:junit4] 2> 229283 T1017 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 229295 T1017 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 229299 T1017 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 229300 T1017 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 229300 T1017 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60810/_e/gd/collection1/
[junit4:junit4] 2> 229300 T1017 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 229300 T1017 oasc.SyncStrategy.syncToMe http://127.0.0.1:60810/_e/gd/collection1/ has no replicas
[junit4:junit4] 2> 229300 T1017 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60810/_e/gd/collection1/
[junit4:junit4] 2> 229301 T1017 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 230198 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 230206 T980 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> 230206 T1000 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> 230206 T1016 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> 230206 T987 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> 230212 T1017 oasc.ZkController.register We are http://127.0.0.1:60810/_e/gd/collection1/ and leader is http://127.0.0.1:60810/_e/gd/collection1/
[junit4:junit4] 2> 230212 T1017 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60810/_e/gd
[junit4:junit4] 2> 230212 T1017 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 230212 T1017 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 230212 T1017 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 230214 T1017 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 230215 T958 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 230215 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 230216 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 230280 T958 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 230282 T958 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39292
[junit4:junit4] 2> 230282 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 230283 T958 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 230283 T958 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.ChaosMonkeySafeLeaderTest-jetty3-1370089589484
[junit4:junit4] 2> 230283 T958 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.ChaosMonkeySafeLeaderTest-jetty3-1370089589484/solr.xml
[junit4:junit4] 2> 230284 T958 oasc.CoreContainer.<init> New CoreContainer 497639890
[junit4:junit4] 2> 230284 T958 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.ChaosMonkeySafeLeaderTest-jetty3-1370089589484/'
[junit4:junit4] 2> 230284 T958 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.ChaosMonkeySafeLeaderTest-jetty3-1370089589484/'
[junit4:junit4] 2> 230324 T958 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 230325 T958 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 230325 T958 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 230325 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 230326 T958 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 230326 T958 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 230326 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 230327 T958 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 230327 T958 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 230327 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 230330 T958 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 230331 T958 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36904/solr
[junit4:junit4] 2> 230331 T958 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 230332 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 230333 T1030 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71b51804 name:ZooKeeperConnection Watcher:127.0.0.1:36904 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 230334 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 230335 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 230338 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 230339 T1032 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@74d19cd1 name:ZooKeeperConnection Watcher:127.0.0.1:36904/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 230340 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 230343 T958 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 231346 T958 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39292__e%2Fgd
[junit4:junit4] 2> 231348 T958 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39292__e%2Fgd
[junit4:junit4] 2> 231352 T1016 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> 231353 T1000 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> 231353 T1032 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 231354 T987 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 231354 T980 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 231354 T987 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> 231355 T980 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> 231356 T1016 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 231357 T1000 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 231364 T1033 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.ChaosMonkeySafeLeaderTest-jetty3-1370089589484/collection1
[junit4:junit4] 2> 231364 T1033 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 231365 T1033 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 231365 T1033 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 231366 T1033 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.ChaosMonkeySafeLeaderTest-jetty3-1370089589484/collection1/'
[junit4:junit4] 2> 231366 T1033 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1370089589484/collection1/lib/README' to classloader
[junit4:junit4] 2> 231367 T1033 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1370089589484/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 231389 T1033 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 231430 T1033 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 231431 T1033 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 231435 T1033 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 231710 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 231711 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:60810__e%2Fgd_collection1",
[junit4:junit4] 2> "numShards":"3",
[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:60810__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:60810/_e/gd"}
[junit4:junit4] 2> 231715 T1032 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> 231715 T980 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> 231715 T1000 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> 231715 T1016 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> 231715 T987 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> 231729 T1033 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 231734 T1033 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 231736 T1033 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 231750 T1033 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 231753 T1033 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 231756 T1033 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 231757 T1033 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 231757 T1033 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 231758 T1033 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 231759 T1033 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 231759 T1033 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 231759 T1033 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 231759 T1033 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.ChaosMonkeySafeLeaderTest-jetty3-1370089589484/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty3/
[junit4:junit4] 2> 231760 T1033 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e24d5d8
[junit4:junit4] 2> 231760 T1033 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 231760 T1033 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty3
[junit4:junit4] 2> 231761 T1033 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty3/index/
[junit4:junit4] 2> 231761 T1033 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 231761 T1033 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty3/index
[junit4:junit4] 2> 231764 T1033 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty3/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 231764 T1033 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 231766 T1033 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 231766 T1033 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 231766 T1033 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 231767 T1033 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 231767 T1033 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 231767 T1033 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 231768 T1033 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 231768 T1033 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 231768 T1033 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 231771 T1033 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 231773 T1033 oass.SolrIndexSearcher.<init> Opening Searcher@410bd296 main
[junit4:junit4] 2> 231774 T1033 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 231774 T1033 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 231778 T1034 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@410bd296 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 231779 T1033 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 231779 T1033 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 233221 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 233223 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"3",
[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:39292__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:39292/_e/gd"}
[junit4:junit4] 2> 233224 T981 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 233225 T981 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard3
[junit4:junit4] 2> 233229 T1032 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> 233230 T980 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> 233230 T1016 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> 233230 T1000 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> 233229 T987 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> 233781 T1033 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 233781 T1033 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39292/_e/gd collection:collection1 shard:shard3
[junit4:junit4] 2> 233782 T1033 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4:junit4] 2> 233787 T1033 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 233790 T1033 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 233790 T1033 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 233790 T1033 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39292/_e/gd/collection1/
[junit4:junit4] 2> 233790 T1033 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 233791 T1033 oasc.SyncStrategy.syncToMe http://127.0.0.1:39292/_e/gd/collection1/ has no replicas
[junit4:junit4] 2> 233791 T1033 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39292/_e/gd/collection1/
[junit4:junit4] 2> 233791 T1033 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4:junit4] 2> 234736 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 234745 T1032 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> 234746 T1016 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> 234746 T1000 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> 234746 T980 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> 234745 T987 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> 234798 T1033 oasc.ZkController.register We are http://127.0.0.1:39292/_e/gd/collection1/ and leader is http://127.0.0.1:39292/_e/gd/collection1/
[junit4:junit4] 2> 234799 T1033 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39292/_e/gd
[junit4:junit4] 2> 234799 T1033 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 234800 T1033 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 234800 T1033 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 234803 T1033 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 234805 T958 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 234806 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 234807 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 234889 T958 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 234891 T958 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47978
[junit4:junit4] 2> 234892 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 234892 T958 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 234892 T958 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.ChaosMonkeySafeLeaderTest-jetty4-1370089594082
[junit4:junit4] 2> 234893 T958 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.ChaosMonkeySafeLeaderTest-jetty4-1370089594082/solr.xml
[junit4:junit4] 2> 234893 T958 oasc.CoreContainer.<init> New CoreContainer 646309920
[junit4:junit4] 2> 234893 T958 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.ChaosMonkeySafeLeaderTest-jetty4-1370089594082/'
[junit4:junit4] 2> 234894 T958 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.ChaosMonkeySafeLeaderTest-jetty4-1370089594082/'
[junit4:junit4] 2> 234951 T958 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 234952 T958 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 234952 T958 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 234952 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 234953 T958 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 234953 T958 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 234953 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 234954 T958 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 234954 T958 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 234954 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 234958 T958 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 234958 T958 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36904/solr
[junit4:junit4] 2> 234959 T958 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 234959 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 234961 T1046 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54ca4ff0 name:ZooKeeperConnection Watcher:127.0.0.1:36904 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 234961 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 234963 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 234966 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 234967 T1048 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@461cc28 name:ZooKeeperConnection Watcher:127.0.0.1:36904/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 234968 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 234971 T958 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 235973 T958 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47978__e%2Fgd
[junit4:junit4] 2> 235975 T958 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47978__e%2Fgd
[junit4:junit4] 2> 235977 T1032 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> 235977 T1000 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> 235978 T1016 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> 235978 T987 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 235978 T980 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 235978 T1048 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 235978 T987 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> 235978 T980 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> 235980 T1032 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 235980 T1000 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 235980 T1016 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 235984 T1049 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.ChaosMonkeySafeLeaderTest-jetty4-1370089594082/collection1
[junit4:junit4] 2> 235984 T1049 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 235985 T1049 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 235985 T1049 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 235986 T1049 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.ChaosMonkeySafeLeaderTest-jetty4-1370089594082/collection1/'
[junit4:junit4] 2> 235987 T1049 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1370089594082/collection1/lib/README' to classloader
[junit4:junit4] 2> 235987 T1049 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1370089594082/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 236010 T1049 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 236038 T1049 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 236039 T1049 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 236042 T1049 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 236254 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 236255 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:39292__e%2Fgd_collection1",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard3",
[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:39292__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:39292/_e/gd"}
[junit4:junit4] 2> 236259 T987 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> 236259 T1016 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> 236259 T1000 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> 236259 T980 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> 236259 T1032 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> 236259 T1048 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> 236344 T1049 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 236349 T1049 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 236351 T1049 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 236365 T1049 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 236368 T1049 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 236371 T1049 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 236372 T1049 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 236372 T1049 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 236373 T1049 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 236374 T1049 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 236374 T1049 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 236374 T1049 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 236374 T1049 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.ChaosMonkeySafeLeaderTest-jetty4-1370089594082/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty4/
[junit4:junit4] 2> 236374 T1049 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e24d5d8
[junit4:junit4] 2> 236375 T1049 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 236375 T1049 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty4
[junit4:junit4] 2> 236375 T1049 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty4/index/
[junit4:junit4] 2> 236376 T1049 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 236376 T1049 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty4/index
[junit4:junit4] 2> 236379 T1049 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty4/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 236379 T1049 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 236381 T1049 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 236381 T1049 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 236382 T1049 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 236382 T1049 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 236383 T1049 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 236383 T1049 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 236383 T1049 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 236383 T1049 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 236384 T1049 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 236386 T1049 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 236389 T1049 oass.SolrIndexSearcher.<init> Opening Searcher@2e40da8d main
[junit4:junit4] 2> 236389 T1049 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 236390 T1049 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 236417 T1050 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2e40da8d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 236418 T1049 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 236418 T1049 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 237764 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 237765 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"3",
[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:47978__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:47978/_e/gd"}
[junit4:junit4] 2> 237766 T981 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 237766 T981 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 237770 T1032 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> 237770 T1016 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> 237770 T1048 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> 237770 T1000 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> 237770 T987 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> 237770 T980 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> 238420 T1049 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 238420 T1049 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:47978/_e/gd collection:collection1 shard:shard1
[junit4:junit4] 2> 238422 T1049 oasc.ZkController.register We are http://127.0.0.1:47978/_e/gd/collection1/ and leader is http://127.0.0.1:58725/_e/gd/collection1/
[junit4:junit4] 2> 238423 T1049 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47978/_e/gd
[junit4:junit4] 2> 238423 T1049 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 238423 T1049 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C281 name=collection1 org.apache.solr.core.SolrCore@7964eff url=http://127.0.0.1:47978/_e/gd/collection1 node=127.0.0.1:47978__e%2Fgd C281_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:47978__e%2Fgd, base_url=http://127.0.0.1:47978/_e/gd}
[junit4:junit4] 2> 238423 T1051 C281 P47978 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 238424 T1049 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 238424 T1051 C281 P47978 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 238424 T1051 C281 P47978 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 238425 T1051 C281 P47978 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 238425 T958 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 238425 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 238426 T1051 C281 P47978 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 238426 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 238430 T994 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:47978__e%2Fgd_collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 238496 T958 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 238499 T958 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:35463
[junit4:junit4] 2> 238499 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 238500 T958 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 238500 T958 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.ChaosMonkeySafeLeaderTest-jetty5-1370089597694
[junit4:junit4] 2> 238500 T958 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.ChaosMonkeySafeLeaderTest-jetty5-1370089597694/solr.xml
[junit4:junit4] 2> 238501 T958 oasc.CoreContainer.<init> New CoreContainer 1944457633
[junit4:junit4] 2> 238501 T958 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.ChaosMonkeySafeLeaderTest-jetty5-1370089597694/'
[junit4:junit4] 2> 238501 T958 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.ChaosMonkeySafeLeaderTest-jetty5-1370089597694/'
[junit4:junit4] 2> 238545 T958 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 238546 T958 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 238546 T958 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 238547 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 238547 T958 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 238547 T958 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 238548 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 238548 T958 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 238548 T958 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 238549 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 238552 T958 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 238553 T958 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36904/solr
[junit4:junit4] 2> 238553 T958 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 238554 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 238555 T1063 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18fee08d name:ZooKeeperConnection Watcher:127.0.0.1:36904 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 238556 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 238557 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 238560 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 238562 T1065 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b74147c name:ZooKeeperConnection Watcher:127.0.0.1:36904/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 238562 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 238566 T958 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 239275 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 239276 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:47978__e%2Fgd_collection1",
[junit4:junit4] 2> "numShards":"3",
[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:47978__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:47978/_e/gd"}
[junit4:junit4] 2> 239281 T1032 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> 239281 T980 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> 239281 T1016 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> 239281 T1000 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> 239281 T1048 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> 239281 T987 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> 239281 T1065 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> 239431 T994 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:47978__e%2Fgd_collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 239432 T994 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:47978__e%252Fgd_collection1&state=recovering&nodeName=127.0.0.1:47978__e%252Fgd&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1002
[junit4:junit4] 2> 239569 T958 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35463__e%2Fgd
[junit4:junit4] 2> 239570 T958 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35463__e%2Fgd
[junit4:junit4] 2> 239572 T1032 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> 239572 T1000 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> 239572 T1016 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> 239572 T1065 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 239572 T980 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 239573 T980 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> 239572 T987 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 239573 T1048 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 239573 T1065 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> 239574 T1032 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 239573 T1048 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> 239574 T1000 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 239573 T987 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> 239574 T1016 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 239577 T1066 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.ChaosMonkeySafeLeaderTest-jetty5-1370089597694/collection1
[junit4:junit4] 2> 239578 T1066 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 239578 T1066 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 239578 T1066 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 239579 T1066 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.ChaosMonkeySafeLeaderTest-jetty5-1370089597694/collection1/'
[junit4:junit4] 2> 239580 T1066 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1370089597694/collection1/lib/README' to classloader
[junit4:junit4] 2> 239580 T1066 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1370089597694/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 239603 T1066 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 239631 T1066 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 239633 T1066 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 239636 T1066 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 239950 T1066 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 239955 T1066 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 239957 T1066 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 239969 T1066 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 239972 T1066 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 239975 T1066 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 239976 T1066 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 239976 T1066 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 239977 T1066 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 239978 T1066 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 239978 T1066 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 239978 T1066 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 239978 T1066 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.ChaosMonkeySafeLeaderTest-jetty5-1370089597694/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty5/
[junit4:junit4] 2> 239979 T1066 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e24d5d8
[junit4:junit4] 2> 239979 T1066 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 239979 T1066 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty5
[junit4:junit4] 2> 239980 T1066 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty5/index/
[junit4:junit4] 2> 239980 T1066 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty5/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 239980 T1066 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty5/index
[junit4:junit4] 2> 239984 T1066 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty5/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 239984 T1066 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 239985 T1066 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 239986 T1066 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 239986 T1066 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 239987 T1066 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 239987 T1066 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 239987 T1066 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 239988 T1066 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 239988 T1066 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 239988 T1066 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 239990 T1066 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 239993 T1066 oass.SolrIndexSearcher.<init> Opening Searcher@2375e960 main
[junit4:junit4] 2> 239993 T1066 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 239994 T1066 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 239999 T1067 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2375e960 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 240001 T1066 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 240001 T1066 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 240787 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 240789 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"3",
[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:35463__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:35463/_e/gd"}
[junit4:junit4] 2> 240789 T981 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 240790 T981 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 240797 T1032 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> 240798 T1048 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> 240798 T987 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> 240798 T1016 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> 240798 T1065 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> 240798 T1000 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> 240798 T980 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> 241003 T1066 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 241003 T1066 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35463/_e/gd collection:collection1 shard:shard2
[junit4:junit4] 2> 241006 T1066 oasc.ZkController.register We are http://127.0.0.1:35463/_e/gd/collection1/ and leader is http://127.0.0.1:60810/_e/gd/collection1/
[junit4:junit4] 2> 241006 T1066 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35463/_e/gd
[junit4:junit4] 2> 241006 T1066 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 241006 T1066 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C282 name=collection1 org.apache.solr.core.SolrCore@5d6a8418 url=http://127.0.0.1:35463/_e/gd/collection1 node=127.0.0.1:35463__e%2Fgd C282_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:35463__e%2Fgd, base_url=http://127.0.0.1:35463/_e/gd}
[junit4:junit4] 2> 241007 T1068 C282 P35463 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 241007 T1068 C282 P35463 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 241008 T1066 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 241008 T1068 C282 P35463 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 241008 T1068 C282 P35463 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 241008 T958 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 241009 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 241009 T1068 C282 P35463 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 241009 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 241015 T1012 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:35463__e%2Fgd_collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 241077 T958 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 241079 T958 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:42235
[junit4:junit4] 2> 241080 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 241080 T958 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 241081 T958 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.ChaosMonkeySafeLeaderTest-jetty6-1370089600279
[junit4:junit4] 2> 241081 T958 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.ChaosMonkeySafeLeaderTest-jetty6-1370089600279/solr.xml
[junit4:junit4] 2> 241081 T958 oasc.CoreContainer.<init> New CoreContainer 1931722511
[junit4:junit4] 2> 241082 T958 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.ChaosMonkeySafeLeaderTest-jetty6-1370089600279/'
[junit4:junit4] 2> 241082 T958 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.ChaosMonkeySafeLeaderTest-jetty6-1370089600279/'
[junit4:junit4] 2> 241123 T958 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 241124 T958 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 241124 T958 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 241124 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 241125 T958 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 241125 T958 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 241125 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 241126 T958 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 241126 T958 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 241126 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 241129 T958 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 241130 T958 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36904/solr
[junit4:junit4] 2> 241130 T958 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 241131 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 241132 T1080 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75f92fac name:ZooKeeperConnection Watcher:127.0.0.1:36904 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 241133 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 241134 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 241137 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 241138 T1082 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70796017 name:ZooKeeperConnection Watcher:127.0.0.1:36904/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 241139 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 241142 T958 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C283 name=collection1 org.apache.solr.core.SolrCore@7964eff url=http://127.0.0.1:47978/_e/gd/collection1 node=127.0.0.1:47978__e%2Fgd C283_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:47978__e%2Fgd, base_url=http://127.0.0.1:47978/_e/gd}
[junit4:junit4] 2> 241433 T1051 C283 P47978 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:58725/_e/gd/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 241433 T1051 C283 P47978 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:47978/_e/gd START replicas=[http://127.0.0.1:58725/_e/gd/collection1/] nUpdates=100
[junit4:junit4] 2> 241433 T1051 C283 P47978 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 241434 T1051 C283 P47978 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 241434 T1051 C283 P47978 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 241434 T1051 C283 P47978 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 241434 T1051 C283 P47978 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 241435 T1051 C283 P47978 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:58725/_e/gd/collection1/. core=collection1
[junit4:junit4] 2> 241435 T1051 C283 P47978 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C284 name=collection1 org.apache.solr.core.SolrCore@fb9b7e4 url=http://127.0.0.1:58725/_e/gd/collection1 node=127.0.0.1:58725__e%2Fgd C284_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:58725__e%2Fgd, base_url=http://127.0.0.1:58725/_e/gd, leader=true}
[junit4:junit4] 2> 241438 T995 C284 P58725 oasc.SolrCore.execute [collection1] webapp=/_e/gd path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 241438 T993 C284 P58725 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 241441 T993 C284 P58725 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty1/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 241441 T993 C284 P58725 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 241452 T993 C284 P58725 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty1/index,segFN=segments_1,generation=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.ChaosMonkeySafeLeaderTest-1370089576954/jetty1/index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 241453 T993 C284 P58725 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 241453 T993 C284 P58725 oass.SolrIndexSearcher.<init> Opening Searcher@1abcd698 realtime
[junit4:junit4] 2> 241453 T993 C284 P58725 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 241454 T993 C284 P58725 oasup.LogUpdateProcessor.finish [collection1] webapp=/_e/gd path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 16
[junit4:junit4] 2> 241454 T1051 C283 P47978 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 241455 T1051 C283 P47978 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 241456 T996 C284 P58725 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 241457 T996 C284 P58725 oasc.SolrCore.execute [collection1] webapp=/_e/gd path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 241457 T1051 C283 P47978 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 241457 T1051 C283 P47978 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 241458 T1051 C283 P47978 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 241460 T995 C284 P58725 oasc.SolrCore.execute [collection1] webapp=/_e/gd path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4:junit4] 2> 241460 T1051 C283 P47978 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 241461 T1051 C283 P47978 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty4/index.20130601082640725
[junit4:junit4] 2> 241461 T1051 C283 P47978 oash.SnapPuller.fetchLatestIndex Starting download to org.apache.lucene.store.MMapDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty4/index.20130601082640725 lockFactory=org.apache.lucene.store.NativeFSLockFactory@12daacbb fullCopy=false
[junit4:junit4] 2> 241463 T993 C284 P58725 oasc.SolrCore.execute [collection1] webapp=/_e/gd path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 241464 T1051 C283 P47978 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 241473 T1051 C283 P47978 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 241473 T1051 C283 P47978 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 241475 T1051 C283 P47978 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty4/index,segFN=segments_1,generation=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.ChaosMonkeySafeLeaderTest-1370089576954/jetty4/index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 241475 T1051 C283 P47978 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 241475 T1051 C283 P47978 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 241476 T1051 C283 P47978 oass.SolrIndexSearcher.<init> Opening Searcher@3ce455a4 main
[junit4:junit4] 2> 241477 T1050 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3ce455a4 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 241477 T1051 C283 P47978 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty4/index.20130601082640725 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty4/index.20130601082640725;done=true>>]
[junit4:junit4] 2> 241477 T1051 C283 P47978 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty4/index.20130601082640725
[junit4:junit4] 2> 241477 T1051 C283 P47978 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty4/index.20130601082640725
[junit4:junit4] 2> 241478 T1051 C283 P47978 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 241478 T1051 C283 P47978 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 241478 T1051 C283 P47978 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 241478 T1051 C283 P47978 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 241480 T1051 C283 P47978 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 242145 T958 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42235__e%2Fgd
[junit4:junit4] 2> 242146 T958 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42235__e%2Fgd
[junit4:junit4] 2> 242148 T1032 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> 242149 T1016 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> 242149 T1000 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> 242150 T1065 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 242150 T1048 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 242150 T1065 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> 242150 T987 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 242151 T1082 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 242151 T980 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 242151 T1048 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> 242151 T980 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> 242151 T987 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> 242153 T1032 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 242153 T1016 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 242154 T1000 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 242159 T1085 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.ChaosMonkeySafeLeaderTest-jetty6-1370089600279/collection1
[junit4:junit4] 2> 242159 T1085 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 242160 T1085 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 242160 T1085 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 242161 T1085 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.ChaosMonkeySafeLeaderTest-jetty6-1370089600279/collection1/'
[junit4:junit4] 2> 242162 T1085 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1370089600279/collection1/lib/README' to classloader
[junit4:junit4] 2> 242162 T1085 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1370089600279/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 242188 T1085 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 242215 T1085 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 242217 T1085 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 242220 T1085 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 242305 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 242306 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:35463__e%2Fgd_collection1",
[junit4:junit4] 2> "numShards":"3",
[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:35463__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:35463/_e/gd"}
[junit4:junit4] 2> 242326 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:47978__e%2Fgd_collection1",
[junit4:junit4] 2> "numShards":"3",
[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:47978__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:47978/_e/gd"}
[junit4:junit4] 2> 242330 T1048 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> 242330 T1000 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> 242330 T980 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> 242330 T1016 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> 242330 T987 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> 242330 T1082 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> 242330 T1065 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> 242330 T1032 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> 242543 T1085 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 242548 T1085 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 242550 T1085 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 242561 T1085 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 242564 T1085 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 242567 T1085 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 242568 T1085 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 242568 T1085 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 242568 T1085 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 242569 T1085 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 242569 T1085 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 242569 T1085 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 242570 T1085 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.ChaosMonkeySafeLeaderTest-jetty6-1370089600279/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty6/
[junit4:junit4] 2> 242570 T1085 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e24d5d8
[junit4:junit4] 2> 242570 T1085 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 242571 T1085 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty6
[junit4:junit4] 2> 242571 T1085 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty6/index/
[junit4:junit4] 2> 242571 T1085 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty6/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 242571 T1085 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty6/index
[junit4:junit4] 2> 242576 T1085 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty6/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 242576 T1085 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 242578 T1085 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 242578 T1085 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 242579 T1085 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 242579 T1085 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 242580 T1085 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 242580 T1085 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 242580 T1085 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 242581 T1085 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 242581 T1085 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 242583 T1085 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 242586 T1085 oass.SolrIndexSearcher.<init> Opening Searcher@50b9934a main
[junit4:junit4] 2> 242587 T1085 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 242587 T1085 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 242590 T1086 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@50b9934a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 242592 T1085 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 242592 T1085 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 243016 T1012 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:35463__e%2Fgd_collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 243016 T1012 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:35463__e%252Fgd_collection1&state=recovering&nodeName=127.0.0.1:35463__e%252Fgd&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2001
[junit4:junit4] 2> 243837 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 243838 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"3",
[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:42235__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42235/_e/gd"}
[junit4:junit4] 2> 243838 T981 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 243839 T981 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard3
[junit4:junit4] 2> 243844 T1032 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> 243844 T1016 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> 243844 T1082 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> 243844 T1000 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> 243844 T987 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> 243844 T1048 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> 243844 T980 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> 243844 T1065 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> 244593 T1085 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 244594 T1085 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42235/_e/gd collection:collection1 shard:shard3
[junit4:junit4] 2> 244596 T1085 oasc.ZkController.register We are http://127.0.0.1:42235/_e/gd/collection1/ and leader is http://127.0.0.1:39292/_e/gd/collection1/
[junit4:junit4] 2> 244597 T1085 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42235/_e/gd
[junit4:junit4] 2> 244597 T1085 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 244597 T1085 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C285 name=collection1 org.apache.solr.core.SolrCore@6982a761 url=http://127.0.0.1:42235/_e/gd/collection1 node=127.0.0.1:42235__e%2Fgd C285_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:42235__e%2Fgd, base_url=http://127.0.0.1:42235/_e/gd}
[junit4:junit4] 2> 244597 T1087 C285 P42235 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 244598 T1087 C285 P42235 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 244598 T1085 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 244598 T1087 C285 P42235 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 244599 T1087 C285 P42235 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 244599 T958 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 244600 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 244600 T1087 C285 P42235 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 244600 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 244606 T1027 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:42235__e%2Fgd_collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 244673 T958 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 244676 T958 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46017
[junit4:junit4] 2> 244676 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 244677 T958 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 244677 T958 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.ChaosMonkeySafeLeaderTest-jetty7-1370089603870
[junit4:junit4] 2> 244677 T958 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.ChaosMonkeySafeLeaderTest-jetty7-1370089603870/solr.xml
[junit4:junit4] 2> 244678 T958 oasc.CoreContainer.<init> New CoreContainer 2051718290
[junit4:junit4] 2> 244678 T958 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.ChaosMonkeySafeLeaderTest-jetty7-1370089603870/'
[junit4:junit4] 2> 244678 T958 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.ChaosMonkeySafeLeaderTest-jetty7-1370089603870/'
[junit4:junit4] 2> 244719 T958 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 244720 T958 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 244720 T958 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 244721 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 244721 T958 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 244721 T958 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 244721 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 244722 T958 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 244722 T958 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 244722 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 244726 T958 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 244726 T958 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36904/solr
[junit4:junit4] 2> 244727 T958 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 244727 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 244729 T1099 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7551e2ff name:ZooKeeperConnection Watcher:127.0.0.1:36904 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 244729 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 244731 T958 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 244734 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 244735 T1101 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@76bb6565 name:ZooKeeperConnection Watcher:127.0.0.1:36904/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 244735 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 244738 T958 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C286 name=collection1 org.apache.solr.core.SolrCore@5d6a8418 url=http://127.0.0.1:35463/_e/gd/collection1 node=127.0.0.1:35463__e%2Fgd C286_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:35463__e%2Fgd, base_url=http://127.0.0.1:35463/_e/gd}
[junit4:junit4] 2> 245017 T1068 C286 P35463 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:60810/_e/gd/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 245018 T1068 C286 P35463 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35463/_e/gd START replicas=[http://127.0.0.1:60810/_e/gd/collection1/] nUpdates=100
[junit4:junit4] 2> 245018 T1068 C286 P35463 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 245018 T1068 C286 P35463 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 245019 T1068 C286 P35463 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 245019 T1068 C286 P35463 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 245019 T1068 C286 P35463 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 245019 T1068 C286 P35463 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:60810/_e/gd/collection1/. core=collection1
[junit4:junit4] 2> 245019 T1068 C286 P35463 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C287 name=collection1 org.apache.solr.core.SolrCore@29fc84c8 url=http://127.0.0.1:60810/_e/gd/collection1 node=127.0.0.1:60810__e%2Fgd C287_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:60810__e%2Fgd, base_url=http://127.0.0.1:60810/_e/gd, leader=true}
[junit4:junit4] 2> 245023 T1010 C287 P60810 oasc.SolrCore.execute [collection1] webapp=/_e/gd path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 245023 T1009 C287 P60810 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 245025 T1009 C287 P60810 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty2/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 245026 T1009 C287 P60810 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 245032 T1009 C287 P60810 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty2/index,segFN=segments_1,generation=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.ChaosMonkeySafeLeaderTest-1370089576954/jetty2/index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 245033 T1009 C287 P60810 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 245033 T1009 C287 P60810 oass.SolrIndexSearcher.<init> Opening Searcher@4efb661d realtime
[junit4:junit4] 2> 245033 T1009 C287 P60810 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 245034 T1009 C287 P60810 oasup.LogUpdateProcessor.finish [collection1] webapp=/_e/gd path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 11
[junit4:junit4] 2> 245034 T1068 C286 P35463 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 245035 T1068 C286 P35463 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 245036 T1011 C287 P60810 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 245036 T1011 C287 P60810 oasc.SolrCore.execute [collection1] webapp=/_e/gd path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 245037 T1068 C286 P35463 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 245037 T1068 C286 P35463 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 245037 T1068 C286 P35463 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 245039 T1010 C287 P60810 oasc.SolrCore.execute [collection1] webapp=/_e/gd path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 245040 T1068 C286 P35463 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 245040 T1068 C286 P35463 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty5/index.20130601082644305
[junit4:junit4] 2> 245041 T1068 C286 P35463 oash.SnapPuller.fetchLatestIndex Starting download to org.apache.lucene.store.MMapDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty5/index.20130601082644305 lockFactory=org.apache.lucene.store.NativeFSLockFactory@34b903a0 fullCopy=false
[junit4:junit4] 2> 245043 T1009 C287 P60810 oasc.SolrCore.execute [collection1] webapp=/_e/gd path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 245044 T1068 C286 P35463 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 245053 T1068 C286 P35463 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 245053 T1068 C286 P35463 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 245055 T1068 C286 P35463 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty5/index,segFN=segments_1,generation=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.ChaosMonkeySafeLeaderTest-1370089576954/jetty5/index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 245055 T1068 C286 P35463 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 245056 T1068 C286 P35463 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 245056 T1068 C286 P35463 oass.SolrIndexSearcher.<init> Opening Searcher@237c2751 main
[junit4:junit4] 2> 245057 T1067 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@237c2751 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 245057 T1068 C286 P35463 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty5/index.20130601082644305 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty5/index.20130601082644305;done=true>>]
[junit4:junit4] 2> 245057 T1068 C286 P35463 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty5/index.20130601082644305
[junit4:junit4] 2> 245058 T1068 C286 P35463 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty5/index.20130601082644305
[junit4:junit4] 2> 245058 T1068 C286 P35463 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 245058 T1068 C286 P35463 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 245058 T1068 C286 P35463 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 245058 T1068 C286 P35463 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 245073 T1068 C286 P35463 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 245349 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 245350 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42235__e%2Fgd_collection1",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard3",
[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:42235__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42235/_e/gd"}
[junit4:junit4] 2> 245353 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:35463__e%2Fgd_collection1",
[junit4:junit4] 2> "numShards":"3",
[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:35463__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:35463/_e/gd"}
[junit4:junit4] 2> 245357 T1032 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> 245357 T980 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> 245357 T1082 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> 245357 T1016 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> 245357 T1048 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> 245357 T1101 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> 245357 T1065 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> 245357 T1000 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> 245357 T987 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> 245606 T1027 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:42235__e%2Fgd_collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 245607 T1027 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:42235__e%252Fgd_collection1&state=recovering&nodeName=127.0.0.1:42235__e%252Fgd&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1001
[junit4:junit4] 2> 245741 T958 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46017__e%2Fgd
[junit4:junit4] 2> 245743 T958 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46017__e%2Fgd
[junit4:junit4] 2> 245744 T1032 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> 245745 T1016 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> 245744 T1101 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> 245745 T1000 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> 245745 T1065 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 245745 T1065 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> 245745 T1082 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> 245746 T987 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 245746 T1048 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 245746 T987 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> 245746 T980 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 245746 T1048 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> 245747 T980 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> 245747 T1032 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 245748 T1016 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 245748 T1000 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 245748 T1101 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 245749 T1082 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 245753 T1104 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.ChaosMonkeySafeLeaderTest-jetty7-1370089603870/collection1
[junit4:junit4] 2> 245753 T1104 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 245754 T1104 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 245754 T1104 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 245755 T1104 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.ChaosMonkeySafeLeaderTest-jetty7-1370089603870/collection1/'
[junit4:junit4] 2> 245756 T1104 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1370089603870/collection1/lib/README' to classloader
[junit4:junit4] 2> 245756 T1104 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1370089603870/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 245799 T1104 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 245827 T1104 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 245828 T1104 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 245834 T1104 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 246208 T1104 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 246213 T1104 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 246216 T1104 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 246227 T1104 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 246230 T1104 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 246233 T1104 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 246234 T1104 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 246234 T1104 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 246234 T1104 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 246235 T1104 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 246235 T1104 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 246235 T1104 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 246236 T1104 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.ChaosMonkeySafeLeaderTest-jetty7-1370089603870/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty7/
[junit4:junit4] 2> 246236 T1104 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e24d5d8
[junit4:junit4] 2> 246236 T1104 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 246237 T1104 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty7
[junit4:junit4] 2> 246237 T1104 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty7/index/
[junit4:junit4] 2> 246238 T1104 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty7/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 246238 T1104 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty7/index
[junit4:junit4] 2> 246241 T1104 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty7/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 246242 T1104 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 246243 T1104 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 246244 T1104 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 246244 T1104 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 246245 T1104 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 246245 T1104 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 246245 T1104 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 246246 T1104 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 246246 T1104 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 246246 T1104 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 246249 T1104 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 246251 T1104 oass.SolrIndexSearcher.<init> Opening Searcher@3d5327cb main
[junit4:junit4] 2> 246252 T1104 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 246252 T1104 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 246256 T1105 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3d5327cb main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 246257 T1104 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 246258 T1104 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 246864 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 246865 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"3",
[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:46017__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:46017/_e/gd"}
[junit4:junit4] 2> 246865 T981 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 246865 T981 oasc.Overseer$ClusterStateUpdater.updateState
[...truncated too long message...]
p://127.0.0.1:49565/_e/gd"}
[junit4:junit4] 2> 354863 T1354 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:49565__e%2Fgd_collection1",
[junit4:junit4] 2> "numShards":null,
[junit4:junit4] 2> "shard":"shard2",
[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:49565__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49565/_e/gd"}
[junit4:junit4] 2> 354865 T1354 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:37637__e%2Fgd_collection1",
[junit4:junit4] 2> "shard":"shard3",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:37637__e%2Fgd",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37637/_e/gd"}
[junit4:junit4] 2> 354868 T1196 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> 355504 T958 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 355505 T958 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 355507 T958 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1643a960
[junit4:junit4] 2> 355508 T958 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=2,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=426,cumulative_deletesById=210,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4] 2> 355509 T958 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 355509 T958 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 355509 T958 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 355510 T958 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 355512 T958 oasc.CachingDirectoryFactory.close Closing StandardDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 355512 T958 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty12/index.20130601082705449 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty12/index.20130601082705449;done=false>>]
[junit4:junit4] 2> 355512 T958 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty12/index.20130601082705449
[junit4:junit4] 2> 355512 T958 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.ChaosMonkeySafeLeaderTest-1370089576954/jetty12 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty12;done=false>>]
[junit4:junit4] 2> 355513 T958 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1370089576954/jetty12
[junit4:junit4] 2> 355514 T1354 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89790190515453980-127.0.0.1:37637__e%2Fgd-n_0000000012) am no longer a leader.
[junit4:junit4] 2> 355535 T958 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/_e/gd,null}
[junit4:junit4] 2> 355659 T958 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 355661 T958 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:36904 36904
[junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4] 1> safe stop:
[junit4:junit4] 1> safe stop:
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.method=testDistribSearch -Dtests.seed=F5AC56AF1C458EB1 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=lv_LV -Dtests.timezone=EST5EDT -Dtests.file.encoding=US-ASCII
[junit4:junit4] FAILURE 138s J1 | ChaosMonkeySafeLeaderTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: shard1 is not consistent. Got 224 from http://127.0.0.1:58725/_e/gd/collection1lastClient and got 217 from http://127.0.0.1:47978/_e/gd/collection1
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([F5AC56AF1C458EB1:744AD8B76B1AEE8D]:0)
[junit4:junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:963)
[junit4:junit4] > at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:137)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 355702 T958 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 138021 T957 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4:junit4] 2> 355729 T1241 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 355730 T1241 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> 355730 T1241 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 356815 T1196 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 356815 T1196 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> 356815 T1196 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {range_facet_l=PostingsFormat(name=SimpleText), text=PostingsFormat(name=NestedPulsing), _version_=PostingsFormat(name=SimpleText), rnd_b=PostingsFormat(name=MockRandom), intDefault=PostingsFormat(name=SimpleText), timestamp=PostingsFormat(name=SimpleText), id=PostingsFormat(name=MockRandom), a_t=PostingsFormat(name=SimpleText), range_facet_sl=PostingsFormat(name=NestedPulsing), range_facet_si=Lucene41(blocksize=128), other_tl1=PostingsFormat(name=SimpleText), multiDefault=Lucene41(blocksize=128), a_si=Lucene41(blocksize=128)}, docValues:{}, sim=DefaultSimilarity, locale=lv_LV, timezone=EST5EDT
[junit4:junit4] 2> NOTE: Linux 3.2.0-45-generic amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=8,threads=1,free=121672664,total=277872640
[junit4:junit4] 2> NOTE: All tests run in this JVM: [UniqFieldsUpdateProcessorFactoryTest, TestLazyCores, CurrencyFieldOpenExchangeTest, CopyFieldTest, PathHierarchyTokenizerFactoryTest, IndexSchemaRuntimeFieldTest, SolrCmdDistributorTest, ZkSolrClientTest, XmlUpdateRequestHandlerTest, TestReload, TestMergePolicyConfig, TestRecovery, TestCollationKeyRangeQueries, TestFoldingMultitermQuery, SolrIndexConfigTest, TestStressReorder, TestDistributedGrouping, TestDFRSimilarityFactory, TestAnalyzedSuggestions, TestSolrQueryParserDefaultOperatorResource, TestNumberUtils, TestDefaultSearchFieldResource, DocumentAnalysisRequestHandlerTest, SortByFunctionTest, TestCodecSupport, TestDynamicFieldResource, TestSolrXMLSerializer, BasicDistributedZk2Test, IndexBasedSpellCheckerTest, ChaosMonkeySafeLeaderTest]
[junit4:junit4] Completed on J1 in 139.30s, 1 test, 1 failure <<< FAILURES!
[...truncated 713 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:386: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:366: 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:1243: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:887: There were test failures: 297 suites, 1238 tests, 1 failure, 13 ignored (7 assumptions)
Total time: 39 minutes 8 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_21 -XX:+UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure