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/07/01 13:55:38 UTC
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 597 -
Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/597/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseG1GC
3 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
Test abandoned because suite timeout was reached.
Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
at __randomizedtesting.SeedInfo.seed([296945ECC99D709B]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
Error Message:
Suite timeout exceeded (>= 7200000 msec).
Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
at __randomizedtesting.SeedInfo.seed([296945ECC99D709B]:0)
REGRESSION: org.apache.solr.logging.TestLogWatcher.testLog4jWatcher
Error Message:
expected:<2> but was:<1>
Stack Trace:
java.lang.AssertionError: expected:<2> but was:<1>
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.logging.TestLogWatcher.testLog4jWatcher(TestLogWatcher.java:63)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
at com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.execute(SlaveMain.java:180)
at com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.main(SlaveMain.java:275)
at com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe.main(SlaveMainSafe.java:12)
Build Log:
[...truncated 9742 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4:junit4] 2> 909635 T1671 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /d_m/
[junit4:junit4] 2> 909650 T1671 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-ChaosMonkeySafeLeaderTest-1372672367822
[junit4:junit4] 2> 909652 T1671 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 909653 T1672 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 909753 T1671 oasc.ZkTestServer.run start zk server on port:52814
[junit4:junit4] 2> 909756 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 909766 T1678 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1534368c name:ZooKeeperConnection Watcher:127.0.0.1:52814 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 909767 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 909767 T1671 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 909777 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 909782 T1680 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@768a8828 name:ZooKeeperConnection Watcher:127.0.0.1:52814/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 909782 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 909782 T1671 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 909797 T1671 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 909804 T1671 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 909811 T1671 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 909819 T1671 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 909820 T1671 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 909831 T1671 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 909832 T1671 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 909839 T1671 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 909840 T1671 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 909848 T1671 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 909851 T1671 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 909862 T1671 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 909863 T1671 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 909873 T1671 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 909874 T1671 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 909882 T1671 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 909883 T1671 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 909893 T1671 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 909894 T1671 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 909901 T1671 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 909902 T1671 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 910393 T1671 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 910402 T1671 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52817
[junit4:junit4] 2> 910403 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 910404 T1671 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 910404 T1671 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372672368093
[junit4:junit4] 2> 910405 T1671 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372672368093/solr.xml
[junit4:junit4] 2> 910405 T1671 oasc.CoreContainer.<init> New CoreContainer 1182590131
[junit4:junit4] 2> 910406 T1671 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372672368093/'
[junit4:junit4] 2> 910406 T1671 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372672368093/'
[junit4:junit4] 2> 910569 T1671 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 910570 T1671 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 910572 T1671 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 910576 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 910577 T1671 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 910577 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 910578 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 910578 T1671 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 910579 T1671 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 910579 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 910601 T1671 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 910602 T1671 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52814/solr
[junit4:junit4] 2> 910603 T1671 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 910604 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 910608 T1691 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17fb4917 name:ZooKeeperConnection Watcher:127.0.0.1:52814 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 910609 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 910637 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 910667 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 910672 T1693 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ad45e70 name:ZooKeeperConnection Watcher:127.0.0.1:52814/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 910675 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 910680 T1671 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 910692 T1671 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 910701 T1671 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 910705 T1671 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52817_d_m
[junit4:junit4] 2> 910708 T1671 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52817_d_m
[junit4:junit4] 2> 910716 T1671 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 910729 T1671 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 910740 T1671 oasc.Overseer.start Overseer (id=89959456298106883-127.0.0.1:52817_d_m-n_0000000000) starting
[junit4:junit4] 2> 910749 T1671 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 910759 T1695 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 910762 T1671 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 910769 T1671 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 910774 T1671 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 910788 T1694 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 910789 T1696 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 910789 T1696 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 910800 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 910803 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[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:52817_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52817/d_m"}
[junit4:junit4] 2> 910803 T1694 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 910804 T1694 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 910813 T1693 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> 911797 T1696 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372672368093/collection1
[junit4:junit4] 2> 911797 T1696 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 911799 T1696 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 911799 T1696 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 911803 T1696 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372672368093/collection1/'
[junit4:junit4] 2> 911804 T1696 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372672368093/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 911805 T1696 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372672368093/collection1/lib/README' to classloader
[junit4:junit4] 2> 911885 T1696 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 911976 T1696 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 911980 T1696 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 911987 T1696 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 912939 T1696 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 912939 T1696 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 912940 T1696 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 912960 T1696 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 912966 T1696 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 913004 T1696 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 913017 T1696 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 913025 T1696 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 913029 T1696 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 913029 T1696 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 913030 T1696 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 913034 T1696 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 913035 T1696 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 913035 T1696 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 913036 T1696 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372672368093/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/control/data/
[junit4:junit4] 2> 913036 T1696 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@54a66fe6
[junit4:junit4] 2> 913037 T1696 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 913038 T1696 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/control/data
[junit4:junit4] 2> 913039 T1696 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/control/data/index/
[junit4:junit4] 2> 913040 T1696 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 913041 T1696 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/control/data/index
[junit4:junit4] 2> 913048 T1696 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/control/data/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 913049 T1696 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 913053 T1696 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 913053 T1696 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 913055 T1696 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 913055 T1696 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 913056 T1696 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 913057 T1696 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 913057 T1696 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 913058 T1696 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 913059 T1696 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 913074 T1696 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 913089 T1696 oass.SolrIndexSearcher.<init> Opening Searcher@5c3da67a main
[junit4:junit4] 2> 913091 T1696 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 913091 T1696 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 913098 T1697 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5c3da67a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 913100 T1696 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 913100 T1696 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52817/d_m collection:control_collection shard:shard1
[junit4:junit4] 2> 913102 T1696 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 913123 T1696 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 913131 T1696 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 913131 T1696 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 913132 T1696 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52817/d_m/collection1/
[junit4:junit4] 2> 913132 T1696 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 913132 T1696 oasc.SyncStrategy.syncToMe http://127.0.0.1:52817/d_m/collection1/ has no replicas
[junit4:junit4] 2> 913133 T1696 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52817/d_m/collection1/
[junit4:junit4] 2> 913133 T1696 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 913864 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 913893 T1693 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> 913930 T1696 oasc.ZkController.register We are http://127.0.0.1:52817/d_m/collection1/ and leader is http://127.0.0.1:52817/d_m/collection1/
[junit4:junit4] 2> 913930 T1696 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52817/d_m
[junit4:junit4] 2> 913931 T1696 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 913931 T1696 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 913931 T1696 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 913936 T1696 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 913939 T1671 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 913939 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 913941 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 913965 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 913968 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 913973 T1700 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1263bebe name:ZooKeeperConnection Watcher:127.0.0.1:52814/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 913973 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 913977 T1671 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 913985 T1671 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 914446 T1671 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 914454 T1671 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52821
[junit4:junit4] 2> 914455 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 914456 T1671 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 914456 T1671 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372672372156
[junit4:junit4] 2> 914457 T1671 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372672372156/solr.xml
[junit4:junit4] 2> 914457 T1671 oasc.CoreContainer.<init> New CoreContainer 1896878638
[junit4:junit4] 2> 914458 T1671 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372672372156/'
[junit4:junit4] 2> 914458 T1671 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372672372156/'
[junit4:junit4] 2> 914633 T1671 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 914634 T1671 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 914634 T1671 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 914635 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 914635 T1671 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 914636 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 914637 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 914637 T1671 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 914638 T1671 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 914638 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 914659 T1671 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 914660 T1671 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52814/solr
[junit4:junit4] 2> 914661 T1671 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 914663 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 914667 T1711 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6eb1f39c name:ZooKeeperConnection Watcher:127.0.0.1:52814 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 914668 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 914679 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 914702 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 914705 T1713 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a198458 name:ZooKeeperConnection Watcher:127.0.0.1:52814/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 914706 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 914718 T1671 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 915410 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 915412 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[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:52817_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52817/d_m"}
[junit4:junit4] 2> 915427 T1693 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> 915428 T1700 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> 915428 T1713 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> 915729 T1671 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52821_d_m
[junit4:junit4] 2> 915732 T1671 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52821_d_m
[junit4:junit4] 2> 915739 T1700 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> 915740 T1713 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> 915744 T1693 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 915744 T1693 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> 915757 T1700 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 915757 T1713 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 915768 T1714 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 915769 T1714 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 916945 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 916946 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[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:52821_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52821/d_m"}
[junit4:junit4] 2> 916947 T1694 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 3
[junit4:junit4] 2> 916947 T1694 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 916962 T1693 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> 916963 T1700 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> 916962 T1713 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> 917782 T1714 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372672372156/collection1
[junit4:junit4] 2> 917783 T1714 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 917784 T1714 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 917785 T1714 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 917788 T1714 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372672372156/collection1/'
[junit4:junit4] 2> 917789 T1714 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372672372156/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 917790 T1714 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372672372156/collection1/lib/README' to classloader
[junit4:junit4] 2> 917865 T1714 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 917956 T1714 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 917959 T1714 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 917966 T1714 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 918922 T1714 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 918923 T1714 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 918924 T1714 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 918936 T1714 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 918941 T1714 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 918986 T1714 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 918994 T1714 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 919002 T1714 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 919005 T1714 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 919005 T1714 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 919006 T1714 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 919008 T1714 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 919009 T1714 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 919009 T1714 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 919009 T1714 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372672372156/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty1/
[junit4:junit4] 2> 919010 T1714 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@54a66fe6
[junit4:junit4] 2> 919011 T1714 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 919012 T1714 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty1
[junit4:junit4] 2> 919013 T1714 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty1/index/
[junit4:junit4] 2> 919014 T1714 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 919016 T1714 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty1/index
[junit4:junit4] 2> 919027 T1714 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty1/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 919028 T1714 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 919033 T1714 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 919033 T1714 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 919034 T1714 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 919035 T1714 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 919037 T1714 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 919037 T1714 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 919037 T1714 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 919038 T1714 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 919039 T1714 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 919054 T1714 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 919064 T1714 oass.SolrIndexSearcher.<init> Opening Searcher@4b115946 main
[junit4:junit4] 2> 919066 T1714 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 919067 T1714 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 919074 T1715 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4b115946 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 919079 T1714 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 919079 T1714 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52821/d_m collection:collection1 shard:shard1
[junit4:junit4] 2> 919087 T1714 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 919107 T1714 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 919114 T1714 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 919114 T1714 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 919115 T1714 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52821/d_m/collection1/
[junit4:junit4] 2> 919115 T1714 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 919115 T1714 oasc.SyncStrategy.syncToMe http://127.0.0.1:52821/d_m/collection1/ has no replicas
[junit4:junit4] 2> 919116 T1714 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52821/d_m/collection1/
[junit4:junit4] 2> 919116 T1714 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 919982 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 920005 T1693 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> 920005 T1700 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> 920010 T1713 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> 920062 T1714 oasc.ZkController.register We are http://127.0.0.1:52821/d_m/collection1/ and leader is http://127.0.0.1:52821/d_m/collection1/
[junit4:junit4] 2> 920062 T1714 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52821/d_m
[junit4:junit4] 2> 920063 T1714 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 920063 T1714 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 920063 T1714 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 920067 T1714 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 920070 T1671 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 920070 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 920071 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 920559 T1671 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 920565 T1671 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52824
[junit4:junit4] 2> 920565 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 920566 T1671 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 920567 T1671 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372672378266
[junit4:junit4] 2> 920567 T1671 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372672378266/solr.xml
[junit4:junit4] 2> 920568 T1671 oasc.CoreContainer.<init> New CoreContainer 1510074503
[junit4:junit4] 2> 920568 T1671 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372672378266/'
[junit4:junit4] 2> 920569 T1671 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372672378266/'
[junit4:junit4] 2> 920730 T1671 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 920731 T1671 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 920731 T1671 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 920732 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 920733 T1671 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 920734 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 920734 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 920735 T1671 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 920735 T1671 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 920736 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 920760 T1671 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 920762 T1671 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52814/solr
[junit4:junit4] 2> 920763 T1671 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 920765 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 920769 T1727 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2cb1dfee name:ZooKeeperConnection Watcher:127.0.0.1:52814 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 920770 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 920775 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 920793 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 920797 T1729 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35165ef4 name:ZooKeeperConnection Watcher:127.0.0.1:52814/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 920797 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 920809 T1671 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 921532 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 921534 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[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:52821_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52821/d_m"}
[junit4:junit4] 2> 921545 T1693 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> 921545 T1713 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> 921546 T1729 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> 921549 T1700 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> 921821 T1671 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52824_d_m
[junit4:junit4] 2> 921824 T1671 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52824_d_m
[junit4:junit4] 2> 921829 T1713 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> 921830 T1700 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> 921831 T1729 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> 921833 T1693 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 921834 T1693 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> 921842 T1700 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 921842 T1729 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 921842 T1713 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 921853 T1730 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 921854 T1730 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 923072 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 923074 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[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:52824_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52824/d_m"}
[junit4:junit4] 2> 923074 T1694 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 923074 T1694 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 923099 T1693 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> 923099 T1713 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> 923100 T1700 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> 923101 T1729 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> 923882 T1730 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372672378266/collection1
[junit4:junit4] 2> 923882 T1730 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 923884 T1730 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 923885 T1730 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 923888 T1730 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372672378266/collection1/'
[junit4:junit4] 2> 923889 T1730 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372672378266/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 923890 T1730 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372672378266/collection1/lib/README' to classloader
[junit4:junit4] 2> 924017 T1730 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 924108 T1730 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 924111 T1730 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 924126 T1730 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 925068 T1730 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 925069 T1730 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 925070 T1730 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 925083 T1730 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 925088 T1730 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 925128 T1730 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 925141 T1730 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 925150 T1730 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 925155 T1730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 925155 T1730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 925156 T1730 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 925158 T1730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 925159 T1730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 925159 T1730 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 925159 T1730 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372672378266/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty2/
[junit4:junit4] 2> 925160 T1730 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@54a66fe6
[junit4:junit4] 2> 925161 T1730 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 925162 T1730 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty2
[junit4:junit4] 2> 925163 T1730 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty2/index/
[junit4:junit4] 2> 925164 T1730 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 925165 T1730 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty2/index
[junit4:junit4] 2> 925171 T1730 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty2/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 925171 T1730 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 925176 T1730 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 925177 T1730 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 925178 T1730 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 925179 T1730 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 925180 T1730 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 925180 T1730 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 925181 T1730 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 925182 T1730 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 925183 T1730 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 925198 T1730 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 925208 T1730 oass.SolrIndexSearcher.<init> Opening Searcher@7f10e550 main
[junit4:junit4] 2> 925210 T1730 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 925210 T1730 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 925218 T1731 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7f10e550 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 925221 T1730 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 925222 T1730 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52824/d_m collection:collection1 shard:shard2
[junit4:junit4] 2> 925223 T1730 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 925244 T1730 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 925251 T1730 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 925252 T1730 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 925252 T1730 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52824/d_m/collection1/
[junit4:junit4] 2> 925252 T1730 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 925253 T1730 oasc.SyncStrategy.syncToMe http://127.0.0.1:52824/d_m/collection1/ has no replicas
[junit4:junit4] 2> 925253 T1730 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52824/d_m/collection1/
[junit4:junit4] 2> 925253 T1730 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 926174 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 926201 T1713 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> 926201 T1693 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> 926202 T1729 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> 926201 T1700 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> 926249 T1730 oasc.ZkController.register We are http://127.0.0.1:52824/d_m/collection1/ and leader is http://127.0.0.1:52824/d_m/collection1/
[junit4:junit4] 2> 926252 T1730 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52824/d_m
[junit4:junit4] 2> 926252 T1730 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 926252 T1730 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 926253 T1730 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 926256 T1730 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 926259 T1671 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 926259 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 926260 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 926736 T1671 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 926743 T1671 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52827
[junit4:junit4] 2> 926744 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 926745 T1671 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 926745 T1671 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372672384451
[junit4:junit4] 2> 926745 T1671 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372672384451/solr.xml
[junit4:junit4] 2> 926746 T1671 oasc.CoreContainer.<init> New CoreContainer 1301347565
[junit4:junit4] 2> 926747 T1671 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372672384451/'
[junit4:junit4] 2> 926747 T1671 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372672384451/'
[junit4:junit4] 2> 926971 T1671 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 926971 T1671 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 926972 T1671 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 926972 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 926973 T1671 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 926973 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 926974 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 926975 T1671 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 926975 T1671 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 926976 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 927002 T1671 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 927003 T1671 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52814/solr
[junit4:junit4] 2> 927003 T1671 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 927005 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 927010 T1743 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@25c0a387 name:ZooKeeperConnection Watcher:127.0.0.1:52814 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 927010 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 927015 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 927033 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 927037 T1745 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@37a9b7dd name:ZooKeeperConnection Watcher:127.0.0.1:52814/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 927037 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 927048 T1671 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 927724 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 927725 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[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:52824_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52824/d_m"}
[junit4:junit4] 2> 927737 T1745 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> 927738 T1713 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> 927737 T1693 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> 927741 T1700 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> 927740 T1729 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> 928062 T1671 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52827_d_m
[junit4:junit4] 2> 928064 T1671 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52827_d_m
[junit4:junit4] 2> 928071 T1700 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> 928071 T1729 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> 928071 T1713 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> 928073 T1745 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 928073 T1745 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> 928081 T1729 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 928082 T1693 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 928082 T1693 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> 928090 T1713 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 928092 T1700 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 928103 T1746 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 928103 T1746 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 929260 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 929262 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[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:52827_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52827/d_m"}
[junit4:junit4] 2> 929262 T1694 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 929262 T1694 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard3
[junit4:junit4] 2> 929275 T1745 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> 929275 T1693 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> 929276 T1729 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> 929275 T1700 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> 929275 T1713 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> 930108 T1746 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372672384451/collection1
[junit4:junit4] 2> 930108 T1746 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 930110 T1746 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 930110 T1746 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 930113 T1746 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372672384451/collection1/'
[junit4:junit4] 2> 930115 T1746 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372672384451/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 930115 T1746 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372672384451/collection1/lib/README' to classloader
[junit4:junit4] 2> 930201 T1746 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 930288 T1746 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 930291 T1746 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 930299 T1746 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 931287 T1746 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 931288 T1746 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 931291 T1746 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 931305 T1746 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 931310 T1746 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 931343 T1746 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 931350 T1746 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 931357 T1746 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 931360 T1746 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 931361 T1746 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 931361 T1746 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 931364 T1746 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 931364 T1746 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 931365 T1746 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 931365 T1746 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372672384451/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty3/
[junit4:junit4] 2> 931365 T1746 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@54a66fe6
[junit4:junit4] 2> 931366 T1746 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 931367 T1746 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty3
[junit4:junit4] 2> 931368 T1746 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty3/index/
[junit4:junit4] 2> 931372 T1746 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 931376 T1746 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty3/index
[junit4:junit4] 2> 931382 T1746 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty3/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 931383 T1746 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 931387 T1746 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 931387 T1746 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 931388 T1746 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 931390 T1746 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 931390 T1746 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 931391 T1746 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 931391 T1746 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 931393 T1746 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 931394 T1746 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 931409 T1746 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 931419 T1746 oass.SolrIndexSearcher.<init> Opening Searcher@f15a461 main
[junit4:junit4] 2> 931421 T1746 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 931421 T1746 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 931429 T1747 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f15a461 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 931433 T1746 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 931434 T1746 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52827/d_m collection:collection1 shard:shard3
[junit4:junit4] 2> 931436 T1746 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4:junit4] 2> 931451 T1746 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 931458 T1746 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 931458 T1746 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 931458 T1746 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52827/d_m/collection1/
[junit4:junit4] 2> 931459 T1746 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 931459 T1746 oasc.SyncStrategy.syncToMe http://127.0.0.1:52827/d_m/collection1/ has no replicas
[junit4:junit4] 2> 931460 T1746 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52827/d_m/collection1/
[junit4:junit4] 2> 931460 T1746 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4:junit4] 2> 932306 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 932327 T1693 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> 932328 T1729 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> 932329 T1745 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> 932330 T1713 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> 932331 T1700 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> 932362 T1746 oasc.ZkController.register We are http://127.0.0.1:52827/d_m/collection1/ and leader is http://127.0.0.1:52827/d_m/collection1/
[junit4:junit4] 2> 932362 T1746 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52827/d_m
[junit4:junit4] 2> 932363 T1746 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 932363 T1746 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 932363 T1746 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 932367 T1746 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 932369 T1671 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 932370 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 932371 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 932838 T1671 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 932845 T1671 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52830
[junit4:junit4] 2> 932846 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 932846 T1671 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 932847 T1671 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372672390563
[junit4:junit4] 2> 932848 T1671 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372672390563/solr.xml
[junit4:junit4] 2> 932849 T1671 oasc.CoreContainer.<init> New CoreContainer 473828180
[junit4:junit4] 2> 932850 T1671 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372672390563/'
[junit4:junit4] 2> 932851 T1671 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372672390563/'
[junit4:junit4] 2> 933020 T1671 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 933021 T1671 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 933022 T1671 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 933023 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 933024 T1671 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 933024 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 933024 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 933025 T1671 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 933025 T1671 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 933026 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 933046 T1671 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 933047 T1671 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52814/solr
[junit4:junit4] 2> 933048 T1671 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 933050 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 933055 T1759 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7383ed7a name:ZooKeeperConnection Watcher:127.0.0.1:52814 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 933056 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 933062 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 933079 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 933089 T1761 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@721560df name:ZooKeeperConnection Watcher:127.0.0.1:52814/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 933090 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 933102 T1671 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 933859 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 933860 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[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:52827_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52827/d_m"}
[junit4:junit4] 2> 933872 T1761 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> 933872 T1745 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> 933873 T1700 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> 933873 T1713 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> 933873 T1729 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> 933876 T1693 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> 934112 T1671 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52830_d_m
[junit4:junit4] 2> 934115 T1671 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52830_d_m
[junit4:junit4] 2> 934121 T1700 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> 934122 T1713 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> 934122 T1729 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> 934126 T1761 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> 934131 T1745 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 934131 T1745 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> 934131 T1693 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 934132 T1693 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> 934147 T1713 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 934147 T1729 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 934147 T1761 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 934148 T1700 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 934164 T1762 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 934164 T1762 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 935399 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 935401 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[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:52830_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52830/d_m"}
[junit4:junit4] 2> 935401 T1694 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 935402 T1694 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 935413 T1745 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> 935414 T1693 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> 935414 T1713 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> 935415 T1700 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> 935415 T1729 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> 935424 T1761 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> 936170 T1762 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372672390563/collection1
[junit4:junit4] 2> 936171 T1762 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 936173 T1762 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 936173 T1762 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 936176 T1762 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372672390563/collection1/'
[junit4:junit4] 2> 936177 T1762 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372672390563/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 936178 T1762 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372672390563/collection1/lib/README' to classloader
[junit4:junit4] 2> 936252 T1762 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 936335 T1762 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 936345 T1762 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 936353 T1762 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 937284 T1762 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 937285 T1762 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 937286 T1762 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 937299 T1762 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 937303 T1762 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 937345 T1762 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 937352 T1762 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 937359 T1762 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 937361 T1762 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 937362 T1762 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 937363 T1762 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 937367 T1762 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 937368 T1762 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 937368 T1762 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 937368 T1762 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372672390563/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty4/
[junit4:junit4] 2> 937369 T1762 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@54a66fe6
[junit4:junit4] 2> 937369 T1762 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 937370 T1762 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty4
[junit4:junit4] 2> 937371 T1762 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty4/index/
[junit4:junit4] 2> 937372 T1762 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 937373 T1762 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty4/index
[junit4:junit4] 2> 937384 T1762 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty4/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 937385 T1762 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 937389 T1762 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 937390 T1762 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 937390 T1762 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 937392 T1762 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 937393 T1762 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 937393 T1762 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 937393 T1762 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 937394 T1762 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 937395 T1762 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 937409 T1762 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 937420 T1762 oass.SolrIndexSearcher.<init> Opening Searcher@da26707 main
[junit4:junit4] 2> 937422 T1762 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 937422 T1762 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 937429 T1763 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@da26707 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 937433 T1762 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 937433 T1762 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52830/d_m collection:collection1 shard:shard1
[junit4:junit4] 2> 937441 T1762 oasc.ZkController.register We are http://127.0.0.1:52830/d_m/collection1/ and leader is http://127.0.0.1:52821/d_m/collection1/
[junit4:junit4] 2> 937441 T1762 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52830/d_m
[junit4:junit4] 2> 937443 T1762 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 937445 T1762 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C326 name=collection1 org.apache.solr.core.SolrCore@1d7143fa url=http://127.0.0.1:52830/d_m/collection1 node=127.0.0.1:52830_d_m C326_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:52830_d_m, base_url=http://127.0.0.1:52830/d_m}
[junit4:junit4] 2> 937448 T1764 C326 P52830 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 937449 T1764 C326 P52830 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 937449 T1762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 937449 T1764 C326 P52830 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 937450 T1764 C326 P52830 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 937452 T1671 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 937453 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 937452 T1764 C326 P52830 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 937453 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 937477 T1705 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 937918 T1671 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 937925 T1671 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52834
[junit4:junit4] 2> 937927 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 937927 T1671 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 937928 T1671 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372672395645
[junit4:junit4] 2> 937928 T1671 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372672395645/solr.xml
[junit4:junit4] 2> 937929 T1671 oasc.CoreContainer.<init> New CoreContainer 1920871299
[junit4:junit4] 2> 937930 T1671 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372672395645/'
[junit4:junit4] 2> 937930 T1671 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372672395645/'
[junit4:junit4] 2> 938093 T1671 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 938094 T1671 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 938094 T1671 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 938095 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 938095 T1671 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 938096 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 938096 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 938096 T1671 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 938097 T1671 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 938098 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 938121 T1671 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 938122 T1671 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52814/solr
[junit4:junit4] 2> 938122 T1671 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 938124 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 938128 T1776 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@21e63b05 name:ZooKeeperConnection Watcher:127.0.0.1:52814 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 938130 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 938135 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 938153 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 938162 T1778 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b1bce0e name:ZooKeeperConnection Watcher:127.0.0.1:52814/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 938162 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 938173 T1671 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 938452 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 938454 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[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:52830_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52830/d_m"}
[junit4:junit4] 2> 938464 T1745 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> 938465 T1761 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> 938465 T1778 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> 938466 T1693 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> 938466 T1713 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> 938465 T1700 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> 938468 T1729 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> 938479 T1705 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 938480 T1705 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=5&state=recovering&nodeName=127.0.0.1:52830_d_m&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1003
[junit4:junit4] 2> 939183 T1671 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52834_d_m
[junit4:junit4] 2> 939186 T1671 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52834_d_m
[junit4:junit4] 2> 939192 T1700 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> 939192 T1713 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> 939193 T1761 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> 939193 T1729 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> 939192 T1778 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> 939197 T1745 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 939197 T1745 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> 939200 T1693 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 939200 T1693 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> 939205 T1761 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 939207 T1713 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 939207 T1700 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 939208 T1778 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 939208 T1729 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 939219 T1779 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 939220 T1779 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 939995 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 939997 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"6",
[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:52834_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52834/d_m"}
[junit4:junit4] 2> 939997 T1694 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 939998 T1694 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 940009 T1745 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> 940013 T1778 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> 940016 T1693 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> 940016 T1700 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> 940017 T1761 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> 940017 T1713 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> 940018 T1729 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> 940223 T1779 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372672395645/collection1
[junit4:junit4] 2> 940223 T1779 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 940225 T1779 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 940225 T1779 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 940228 T1779 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372672395645/collection1/'
[junit4:junit4] 2> 940229 T1779 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372672395645/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 940230 T1779 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372672395645/collection1/lib/README' to classloader
[junit4:junit4] 2> 940305 T1779 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 940395 T1779 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 940398 T1779 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 940406 T1779 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> C326_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:52830_d_m, base_url=http://127.0.0.1:52830/d_m}
[junit4:junit4] 2> 940505 T1764 C326 P52830 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:52821/d_m/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 940505 T1764 C326 P52830 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:52830/d_m START replicas=[http://127.0.0.1:52821/d_m/collection1/] nUpdates=100
[junit4:junit4] 2> 940506 T1764 C326 P52830 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 940516 T1764 C326 P52830 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 940516 T1764 C326 P52830 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 940516 T1764 C326 P52830 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 940517 T1764 C326 P52830 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 940517 T1764 C326 P52830 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:52821/d_m/collection1/. core=collection1
[junit4:junit4] 2> 940517 T1764 C326 P52830 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C327 name=collection1 org.apache.solr.core.SolrCore@321a5f57 url=http://127.0.0.1:52821/d_m/collection1 node=127.0.0.1:52821_d_m C327_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:52821_d_m, base_url=http://127.0.0.1:52821/d_m, leader=true}
[junit4:junit4] 2> 940553 T1708 C327 P52821 oasc.SolrCore.execute [collection1] webapp=/d_m path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 940556 T1709 C327 P52821 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 940561 T1709 C327 P52821 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty1/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 940562 T1709 C327 P52821 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 940562 T1709 C327 P52821 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 940563 T1709 C327 P52821 oass.SolrIndexSearcher.<init> Opening Searcher@6569b869 realtime
[junit4:junit4] 2> 940563 T1709 C327 P52821 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 940564 T1709 C327 P52821 oasup.LogUpdateProcessor.finish [collection1] webapp=/d_m path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 8
[junit4:junit4] 2> 940565 T1764 C326 P52830 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 940565 T1764 C326 P52830 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 940580 T1706 C327 P52821 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 940581 T1706 C327 P52821 oasc.SolrCore.execute [collection1] webapp=/d_m path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=3
[junit4:junit4] 2> 940582 T1764 C326 P52830 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 940582 T1764 C326 P52830 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 940582 T1764 C326 P52830 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 940583 T1764 C326 P52830 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 940585 T1764 C326 P52830 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 941356 T1779 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 941357 T1779 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 941358 T1779 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 941376 T1779 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 941382 T1779 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 941414 T1779 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 941421 T1779 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 941429 T1779 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 941432 T1779 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 941433 T1779 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 941433 T1779 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 941436 T1779 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 941436 T1779 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 941436 T1779 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 941437 T1779 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372672395645/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty5/
[junit4:junit4] 2> 941437 T1779 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@54a66fe6
[junit4:junit4] 2> 941439 T1779 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 941444 T1779 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty5
[junit4:junit4] 2> 941445 T1779 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty5/index/
[junit4:junit4] 2> 941446 T1779 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty5/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 941446 T1779 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty5/index
[junit4:junit4] 2> 941453 T1779 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty5/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 941453 T1779 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 941458 T1779 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 941458 T1779 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 941459 T1779 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 941460 T1779 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 941461 T1779 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 941462 T1779 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 941465 T1779 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 941466 T1779 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 941467 T1779 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 941481 T1779 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 941491 T1779 oass.SolrIndexSearcher.<init> Opening Searcher@52043896 main
[junit4:junit4] 2> 941492 T1779 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 941492 T1779 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 941502 T1781 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@52043896 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 941511 T1779 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 941512 T1779 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52834/d_m collection:collection1 shard:shard2
[junit4:junit4] 2> 941519 T1779 oasc.ZkController.register We are http://127.0.0.1:52834/d_m/collection1/ and leader is http://127.0.0.1:52824/d_m/collection1/
[junit4:junit4] 2> 941519 T1779 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52834/d_m
[junit4:junit4] 2> 941520 T1779 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 941520 T1779 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C328 name=collection1 org.apache.solr.core.SolrCore@33bda1c3 url=http://127.0.0.1:52834/d_m/collection1 node=127.0.0.1:52834_d_m C328_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:52834_d_m, base_url=http://127.0.0.1:52834/d_m}
[junit4:junit4] 2> 941522 T1782 C328 P52834 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 941523 T1782 C328 P52834 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 941523 T1782 C328 P52834 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 941524 T1782 C328 P52834 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 941524 T1779 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 941527 T1782 C328 P52834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 941528 T1671 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 941529 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 941530 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 941560 T1723 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 6, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 941571 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 941574 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[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:52830_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52830/d_m"}
[junit4:junit4] 2> 941583 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"6",
[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:52834_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52834/d_m"}
[junit4:junit4] 2> 941599 T1745 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> 941602 T1700 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> 941603 T1778 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> 941605 T1761 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> 941607 T1713 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> 941608 T1729 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> 941610 T1693 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> 942046 T1671 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 942053 T1671 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52841
[junit4:junit4] 2> 942053 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 942054 T1671 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 942054 T1671 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372672399720
[junit4:junit4] 2> 942054 T1671 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372672399720/solr.xml
[junit4:junit4] 2> 942055 T1671 oasc.CoreContainer.<init> New CoreContainer 1898791756
[junit4:junit4] 2> 942055 T1671 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372672399720/'
[junit4:junit4] 2> 942055 T1671 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372672399720/'
[junit4:junit4] 2> 942227 T1671 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 942228 T1671 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 942229 T1671 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 942230 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 942232 T1671 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 942236 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 942236 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 942237 T1671 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 942237 T1671 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 942238 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 942261 T1671 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 942262 T1671 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52814/solr
[junit4:junit4] 2> 942263 T1671 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 942268 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 942277 T1794 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55da5c75 name:ZooKeeperConnection Watcher:127.0.0.1:52814 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 942278 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 942284 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 942301 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 942305 T1796 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f97b8a4 name:ZooKeeperConnection Watcher:127.0.0.1:52814/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 942305 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 942316 T1671 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 942562 T1723 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 6, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 942563 T1723 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=6&state=recovering&nodeName=127.0.0.1:52834_d_m&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1003
[junit4:junit4] 2> 943325 T1671 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52841_d_m
[junit4:junit4] 2> 943328 T1671 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52841_d_m
[junit4:junit4] 2> 943336 T1700 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> 943337 T1761 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> 943337 T1778 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> 943338 T1713 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> 943338 T1729 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> 943343 T1745 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 943343 T1745 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> 943351 T1693 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 943352 T1693 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> 943357 T1778 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 943357 T1761 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 943359 T1700 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 943362 T1713 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 943363 T1729 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 943363 T1796 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 943377 T1797 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 943377 T1797 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> C328_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:52834_d_m, base_url=http://127.0.0.1:52834/d_m}
[junit4:junit4] 2> 944565 T1782 C328 P52834 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:52824/d_m/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 944565 T1782 C328 P52834 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:52834/d_m START replicas=[http://127.0.0.1:52824/d_m/collection1/] nUpdates=100
[junit4:junit4] 2> 944566 T1782 C328 P52834 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 944566 T1782 C328 P52834 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 944566 T1782 C328 P52834 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 944566 T1782 C328 P52834 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 944567 T1782 C328 P52834 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 944569 T1782 C328 P52834 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:52824/d_m/collection1/. core=collection1
[junit4:junit4] 2> 944572 T1782 C328 P52834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C329 name=collection1 org.apache.solr.core.SolrCore@2fc0caf url=http://127.0.0.1:52824/d_m/collection1 node=127.0.0.1:52824_d_m C329_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:52824_d_m, base_url=http://127.0.0.1:52824/d_m, leader=true}
[junit4:junit4] 2> 944587 T1720 C329 P52824 oasc.SolrCore.execute [collection1] webapp=/d_m path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 944593 T1721 C329 P52824 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 944600 T1721 C329 P52824 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty2/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 944600 T1721 C329 P52824 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 944601 T1721 C329 P52824 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 944602 T1721 C329 P52824 oass.SolrIndexSearcher.<init> Opening Searcher@30d95d8f realtime
[junit4:junit4] 2> 944602 T1721 C329 P52824 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 944603 T1721 C329 P52824 oasup.LogUpdateProcessor.finish [collection1] webapp=/d_m path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 10
[junit4:junit4] 2> 944604 T1782 C328 P52834 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 944604 T1782 C328 P52834 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 944610 T1724 C329 P52824 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 944610 T1724 C329 P52824 oasc.SolrCore.execute [collection1] webapp=/d_m path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 944611 T1782 C328 P52834 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 944611 T1782 C328 P52834 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 944612 T1782 C328 P52834 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 944612 T1782 C328 P52834 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 944614 T1782 C328 P52834 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 944661 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 944663 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"7",
[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:52841_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52841/d_m"}
[junit4:junit4] 2> 944664 T1694 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 944664 T1694 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard3
[junit4:junit4] 2> 944673 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"6",
[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:52834_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52834/d_m"}
[junit4:junit4] 2> 944685 T1796 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> 944702 T1778 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> 944702 T1693 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> 944702 T1761 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> 944702 T1713 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> 944703 T1729 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> 944703 T1700 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> 944703 T1745 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> 945381 T1797 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372672399720/collection1
[junit4:junit4] 2> 945382 T1797 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 945384 T1797 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 945384 T1797 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 945387 T1797 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372672399720/collection1/'
[junit4:junit4] 2> 945389 T1797 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372672399720/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 945389 T1797 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372672399720/collection1/lib/README' to classloader
[junit4:junit4] 2> 945466 T1797 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 945562 T1797 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 945565 T1797 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 945573 T1797 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 946586 T1797 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 946587 T1797 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 946588 T1797 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 946602 T1797 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 946607 T1797 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 946650 T1797 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 946658 T1797 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 946665 T1797 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 946668 T1797 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 946668 T1797 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 946669 T1797 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 946672 T1797 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 946672 T1797 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 946673 T1797 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 946673 T1797 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372672399720/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty6/
[junit4:junit4] 2> 946673 T1797 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@54a66fe6
[junit4:junit4] 2> 946674 T1797 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 946675 T1797 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty6
[junit4:junit4] 2> 946676 T1797 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty6/index/
[junit4:junit4] 2> 946677 T1797 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty6/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 946678 T1797 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty6/index
[junit4:junit4] 2> 946693 T1797 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty6/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 946693 T1797 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 946697 T1797 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 946698 T1797 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 946699 T1797 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 946700 T1797 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 946701 T1797 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 946701 T1797 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 946705 T1797 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 946705 T1797 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 946706 T1797 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 946728 T1797 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 946739 T1797 oass.SolrIndexSearcher.<init> Opening Searcher@24e8c68a main
[junit4:junit4] 2> 946741 T1797 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 946741 T1797 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 946749 T1799 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@24e8c68a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 946759 T1797 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 946759 T1797 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52841/d_m collection:collection1 shard:shard3
[junit4:junit4] 2> 946767 T1797 oasc.ZkController.register We are http://127.0.0.1:52841/d_m/collection1/ and leader is http://127.0.0.1:52827/d_m/collection1/
[junit4:junit4] 2> 946767 T1797 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52841/d_m
[junit4:junit4] 2> 946768 T1797 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 946768 T1797 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C330 name=collection1 org.apache.solr.core.SolrCore@257c34b url=http://127.0.0.1:52841/d_m/collection1 node=127.0.0.1:52841_d_m C330_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:52841_d_m, base_url=http://127.0.0.1:52841/d_m}
[junit4:junit4] 2> 946769 T1800 C330 P52841 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 946770 T1800 C330 P52841 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 946770 T1800 C330 P52841 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 946771 T1800 C330 P52841 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 946770 T1797 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 946773 T1800 C330 P52841 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 946798 T1737 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 7, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 946799 T1671 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 946800 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 946800 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 947291 T1671 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 947297 T1671 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52848
[junit4:junit4] 2> 947299 T1671 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 947300 T1671 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 947300 T1671 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372672404989
[junit4:junit4] 2> 947301 T1671 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372672404989/solr.xml
[junit4:junit4] 2> 947301 T1671 oasc.CoreContainer.<init> New CoreContainer 985254099
[junit4:junit4] 2> 947304 T1671 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372672404989/'
[junit4:junit4] 2> 947304 T1671 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372672404989/'
[junit4:junit4] 2> 947473 T1671 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 947474 T1671 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 947474 T1671 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 947474 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 947475 T1671 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 947477 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 947480 T1671 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 947482 T1671 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 947483 T1671 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 947483 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 947506 T1671 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 947507 T1671 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52814/solr
[junit4:junit4] 2> 947507 T1671 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 947511 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 947514 T1812 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@25177871 name:ZooKeeperConnection Watcher:127.0.0.1:52814 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 947515 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 947520 T1671 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 947537 T1671 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 947542 T1814 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67b5460a name:ZooKeeperConnection Watcher:127.0.0.1:52814/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 947543 T1671 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 947561 T1671 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 947715 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 947717 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"7",
[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:52841_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52841/d_m"}
[junit4:junit4] 2> 947728 T1745 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> 947728 T1700 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> 947729 T1814 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> 947729 T1796 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> 947729 T1761 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> 947730 T1778 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> 947731 T1693 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> 947733 T1729 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> 947734 T1713 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> 947800 T1737 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 7, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 947801 T1737 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=7&state=recovering&nodeName=127.0.0.1:52841_d_m&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1003
[junit4:junit4] 2> 948571 T1671 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52848_d_m
[junit4:junit4] 2> 948574 T1671 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52848_d_m
[junit4:junit4] 2> 948582 T1700 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> 948583 T1796 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> 948583 T1778 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> 948583 T1761 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> 948584 T1729 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> 948588 T1713 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> 948591 T1745 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 948591 T1745 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> 948592 T1693 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 948593 T1693 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> 948597 T1814 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 948597 T1814 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> 948606 T1700 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 948610 T1778 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 948610 T1729 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 948611 T1796 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 948613 T1761 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 948615 T1713 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 948630 T1815 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 948631 T1815 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 949255 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 949257 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"8",
[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:52848_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52848/d_m"}
[junit4:junit4] 2> 949257 T1694 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 949257 T1694 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 949268 T1745 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 949268 T1700 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 949269 T1796 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 949270 T1778 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 949271 T1761 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 949273 T1693 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 949273 T1713 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 949275 T1729 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 949276 T1814 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 949642 T1815 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372672404989/collection1
[junit4:junit4] 2> 949642 T1815 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 949644 T1815 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 949644 T1815 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 949648 T1815 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372672404989/collection1/'
[junit4:junit4] 2> 949649 T1815 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372672404989/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 949650 T1815 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372672404989/collection1/lib/README' to classloader
[junit4:junit4] 2> 949728 T1815 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> C330_STATE=coll:collection1 core:collection1 props:{shard=shard3, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:52841_d_m, base_url=http://127.0.0.1:52841/d_m}
[junit4:junit4] 2> 949803 T1800 C330 P52841 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:52827/d_m/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 949803 T1800 C330 P52841 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:52841/d_m START replicas=[http://127.0.0.1:52827/d_m/collection1/] nUpdates=100
[junit4:junit4] 2> 949804 T1800 C330 P52841 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 949805 T1800 C330 P52841 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 949805 T1800 C330 P52841 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 949805 T1800 C330 P52841 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 949806 T1800 C330 P52841 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 949806 T1800 C330 P52841 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:52827/d_m/collection1/. core=collection1
[junit4:junit4] 2> 949806 T1800 C330 P52841 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 949836 T1815 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> ASYNC NEW_CORE C331 name=collection1 org.apache.solr.core.SolrCore@273bdf03 url=http://127.0.0.1:52827/d_m/collection1 node=127.0.0.1:52827_d_m C331_STATE=coll:collection1 core:collection1 props:{shard=shard3, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:52827_d_m, base_url=http://127.0.0.1:52827/d_m, leader=true}
[junit4:junit4] 2> 949838 T1735 C331 P52827 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 949844 T1735 C331 P52827 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty3/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 949849 T1735 C331 P52827 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 949850 T1735 C331 P52827 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 949851 T1735 C331 P52827 oass.SolrIndexSearcher.<init> Opening Searcher@4bbb6f76 realtime
[junit4:junit4] 2> 949852 T1735 C331 P52827 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 949853 T1735 C331 P52827 oasup.LogUpdateProcessor.finish [collection1] webapp=/d_m path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 15
[junit4:junit4] 2> 949852 T1740 C331 P52827 oasc.SolrCore.execute [collection1] webapp=/d_m path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=15
[junit4:junit4] 2> 949856 T1800 C330 P52841 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 949857 T1800 C330 P52841 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 949857 T1815 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 949861 T1738 C331 P52827 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 949862 T1738 C331 P52827 oasc.SolrCore.execute [collection1] webapp=/d_m path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 949863 T1800 C330 P52841 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 949863 T1800 C330 P52841 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 949864 T1800 C330 P52841 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 949864 T1800 C330 P52841 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 949867 T1800 C330 P52841 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 949896 T1815 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 950803 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 950805 T1694 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"7",
[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:52841_d_m",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52841/d_m"}
[junit4:junit4] 2> 950843 T1700 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 950844 T1729 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 950844 T1778 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 950844 T1713 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 950843 T1761 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 950843 T1796 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 950844 T1693 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 950844 T1814 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 950844 T1745 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4] 2> 950888 T1815 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 950890 T1815 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 950891 T1815 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 950903 T1815 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 950907 T1815 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 950940 T1815 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 950948 T1815 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 950955 T1815 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 950959 T1815 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 950959 T1815 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 950961 T1815 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 950967 T1815 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 950968 T1815 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 950968 T1815 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 950969 T1815 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372672404989/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty7/
[junit4:junit4] 2> 950969 T1815 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@54a66fe6
[junit4:junit4] 2> 950970 T1815 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 950971 T1815 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty7
[junit4:junit4] 2> 950972 T1815 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty7/index/
[junit4:junit4] 2> 950973 T1815 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty7/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 950974 T1815 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372672367821/jetty7/index
[junit4:junit4] 2> 950983 T1815 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.Cha
[...truncated too long message...]
Cnxn$SendThread.run WARN Session 0x13f99a61cd60010 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:708)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2>
[junit4:junit4] 2> 8230337 T1777 oaz.ClientCnxn$SendThread.run WARN Session 0x13f99a61cd6000e for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:708)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2>
[junit4:junit4] 2> 8230647 T1903 oaz.ClientCnxn$SendThread.run WARN Session 0x13f99a61cd6001c for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:708)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2>
[junit4:junit4] 2> 8230686 T1976 oaz.ClientCnxn$SendThread.run WARN Session 0x13f99a61cd60021 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:708)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2>
[junit4:junit4] 2> 8230713 T1986 oaz.ClientCnxn$SendThread.run WARN Session 0x13f99a61cd60023 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:708)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2>
[junit4:junit4] 2> 8231962 T1795 oaz.ClientCnxn$SendThread.run WARN Session 0x13f99a61cd60010 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:708)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2>
[junit4:junit4] 2> 8231972 T1777 oaz.ClientCnxn$SendThread.run WARN Session 0x13f99a61cd6000e for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:708)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2>
[junit4:junit4] 2> 8231984 T1982 oaz.ClientCnxn$SendThread.run WARN Session 0x13f99a61cd60022 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:708)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2>
[junit4:junit4] 2> 8232089 T1942 oaz.ClientCnxn$SendThread.run WARN Session 0x13f99a61cd6001e for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:708)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2>
[junit4:junit4] 2> 8232146 T1903 oaz.ClientCnxn$SendThread.run WARN Session 0x13f99a61cd6001c for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:708)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2>
[junit4:junit4] 2> 8232282 T1986 oaz.ClientCnxn$SendThread.run WARN Session 0x13f99a61cd60023 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:708)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2>
[junit4:junit4] 2> 8232760 T1976 oaz.ClientCnxn$SendThread.run WARN Session 0x13f99a61cd60021 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:708)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2>
[junit4:junit4] 2> 8232909 T1 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 8232909 T1 oasl.TestLogWatcher.testLog4jWatcher WARN This is a test message
[junit4:junit4] 2> 8233097 T1777 oaz.ClientCnxn$SendThread.run WARN Session 0x13f99a61cd6000e for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4] 2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:708)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2>
[junit4:junit4] FAILURE 3.74s | TestLogWatcher.testLog4jWatcher <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: expected:<2> but was:<1>
[junit4:junit4] > at org.apache.solr.logging.TestLogWatcher.testLog4jWatcher(TestLogWatcher.java:63)
[junit4:junit4] Completed in 3.97s, 1 test, 1 failure <<< FAILURES!
[...truncated 68 lines...]
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:392: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:372: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:181: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:437: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1248: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:892: There were test failures: 299 suites, 1290 tests, 1 suite-level error, 1 error, 1 failure, 706 ignored
Total time: 189 minutes 48 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure