You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/06/25 16:02:43 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.7.0_25) - Build # 6233
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/6233/
Java: 32bit/jdk1.7.0_25 -client -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
Captured an uncaught exception in thread: Thread[id=841, name=Thread-391, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=841, name=Thread-391, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
Caused by: org.apache.solr.common.SolrException: SolrCore 'collection1' is not available due to init failure: Error opening new searcher
at __randomizedtesting.SeedInfo.seed([940F15D1FF7BA1C1]:0)
at org.apache.solr.core.CoreContainer.getCore(CoreContainer.java:970)
at org.apache.solr.handler.admin.CoreAdminHandler$2.run(CoreAdminHandler.java:795)
Caused by: org.apache.solr.common.SolrException: Error opening new searcher
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:835)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:627)
at org.apache.solr.core.ZkContainer.createFromZk(ZkContainer.java:264)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:764)
at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:437)
at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:429)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:724)
Caused by: org.apache.solr.common.SolrException: Error opening new searcher
at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1512)
at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1624)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:810)
... 13 more
Caused by: org.apache.solr.common.SolrException: Error opening Reader
at org.apache.solr.search.SolrIndexSearcher.getReader(SolrIndexSearcher.java:173)
at org.apache.solr.search.SolrIndexSearcher.<init>(SolrIndexSearcher.java:184)
at org.apache.solr.search.SolrIndexSearcher.<init>(SolrIndexSearcher.java:180)
at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1487)
... 15 more
Caused by: java.lang.AssertionError: liveDocs.count()=15 info.docCount=20 info.getDelCount()=12
at org.apache.lucene.codecs.lucene40.Lucene40LiveDocsFormat.readLiveDocs(Lucene40LiveDocsFormat.java:92)
at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:61)
at org.apache.lucene.index.StandardDirectoryReader$1.doBody(StandardDirectoryReader.java:62)
at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:812)
at org.apache.lucene.index.StandardDirectoryReader.open(StandardDirectoryReader.java:52)
at org.apache.lucene.index.DirectoryReader.open(DirectoryReader.java:88)
at org.apache.solr.core.StandardIndexReaderFactory.newReader(StandardIndexReaderFactory.java:34)
at org.apache.solr.search.SolrIndexSearcher.getReader(SolrIndexSearcher.java:170)
... 18 more
Build Log:
[...truncated 9459 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4:junit4] 2> 171704 T544 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_t/
[junit4:junit4] 2> 171710 T544 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeySafeLeaderTest-1372167998070
[junit4:junit4] 2> 171711 T544 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 171712 T545 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 171812 T544 oasc.ZkTestServer.run start zk server on port:36043
[junit4:junit4] 2> 171813 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 171853 T551 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fcabe5 name:ZooKeeperConnection Watcher:127.0.0.1:36043 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 171854 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 171854 T544 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 171859 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 171860 T553 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17a2254 name:ZooKeeperConnection Watcher:127.0.0.1:36043/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 171860 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 171860 T544 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 171863 T544 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 171865 T544 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 171867 T544 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 171870 T544 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 171870 T544 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 171874 T544 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 171874 T544 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 171877 T544 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 171877 T544 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 171879 T544 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 171880 T544 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 171882 T544 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 171882 T544 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 171885 T544 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 171885 T544 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 171887 T544 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 171888 T544 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 171890 T544 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 171891 T544 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 171893 T544 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 171893 T544 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 171971 T544 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 171974 T544 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50104
[junit4:junit4] 2> 171975 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 171975 T544 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 171976 T544 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372167998254
[junit4:junit4] 2> 171976 T544 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372167998254/solr.xml
[junit4:junit4] 2> 171977 T544 oasc.CoreContainer.<init> New CoreContainer 139963
[junit4:junit4] 2> 171977 T544 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372167998254/'
[junit4:junit4] 2> 171977 T544 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372167998254/'
[junit4:junit4] 2> 172034 T544 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 172034 T544 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 172035 T544 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 172035 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 172036 T544 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 172036 T544 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 172036 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 172037 T544 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 172037 T544 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 172037 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 172040 T544 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 172041 T544 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36043/solr
[junit4:junit4] 2> 172041 T544 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 172042 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 172043 T564 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@90f5 name:ZooKeeperConnection Watcher:127.0.0.1:36043 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 172044 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 172046 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 172049 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 172050 T566 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a7448d name:ZooKeeperConnection Watcher:127.0.0.1:36043/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 172050 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 172052 T544 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 172058 T544 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 172061 T544 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 172064 T544 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50104__t
[junit4:junit4] 2> 172064 T544 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50104__t
[junit4:junit4] 2> 172067 T544 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 172077 T544 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 172080 T544 oasc.Overseer.start Overseer (id=89926401921712131-127.0.0.1:50104__t-n_0000000000) starting
[junit4:junit4] 2> 172083 T544 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 172088 T568 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 172089 T544 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 172093 T544 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 172095 T544 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 172098 T567 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 172101 T569 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 172101 T569 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 173601 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 173601 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50104__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50104/_t"}
[junit4:junit4] 2> 173601 T567 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 173602 T567 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 173604 T566 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> 174102 T569 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372167998254/collection1
[junit4:junit4] 2> 174103 T569 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 174104 T569 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 174104 T569 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 174106 T569 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372167998254/collection1/'
[junit4:junit4] 2> 174107 T569 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372167998254/collection1/lib/README' to classloader
[junit4:junit4] 2> 174107 T569 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372167998254/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 174155 T569 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 174198 T569 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 174200 T569 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 174205 T569 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 174662 T569 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 174662 T569 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 174663 T569 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 174669 T569 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 174671 T569 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 174682 T569 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 174685 T569 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 174690 T569 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 174691 T569 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 174691 T569 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 174691 T569 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 174692 T569 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 174692 T569 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 174693 T569 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 174701 T569 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372167998254/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/control/data/
[junit4:junit4] 2> 174701 T569 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d525d2
[junit4:junit4] 2> 174702 T569 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 174702 T569 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/control/data
[junit4:junit4] 2> 174703 T569 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/control/data/index/
[junit4:junit4] 2> 174703 T569 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 174703 T569 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/control/data/index
[junit4:junit4] 2> 174707 T569 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/control/data/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 174708 T569 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 174709 T569 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 174710 T569 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 174711 T569 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 174711 T569 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 174712 T569 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 174712 T569 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 174712 T569 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 174713 T569 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 174713 T569 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 174716 T569 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 174719 T569 oass.SolrIndexSearcher.<init> Opening Searcher@43dc6f main
[junit4:junit4] 2> 174720 T569 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 174720 T569 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 174725 T570 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@43dc6f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 174725 T569 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 174725 T569 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50104/_t collection:control_collection shard:shard1
[junit4:junit4] 2> 174726 T569 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 174731 T569 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 174734 T569 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 174734 T569 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 174734 T569 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50104/_t/collection1/
[junit4:junit4] 2> 174734 T569 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 174734 T569 oasc.SyncStrategy.syncToMe http://127.0.0.1:50104/_t/collection1/ has no replicas
[junit4:junit4] 2> 174735 T569 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50104/_t/collection1/
[junit4:junit4] 2> 174735 T569 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 175108 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 175114 T566 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> 175147 T569 oasc.ZkController.register We are http://127.0.0.1:50104/_t/collection1/ and leader is http://127.0.0.1:50104/_t/collection1/
[junit4:junit4] 2> 175147 T569 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50104/_t
[junit4:junit4] 2> 175147 T569 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 175147 T569 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 175147 T569 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 175149 T569 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 175149 T544 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 175150 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 175150 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 175153 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 175155 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 175156 T573 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@392ed3 name:ZooKeeperConnection Watcher:127.0.0.1:36043/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 175156 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 175157 T544 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 175159 T544 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 175234 T544 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 175236 T544 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58748
[junit4:junit4] 2> 175237 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 175237 T544 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 175237 T544 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372168001518
[junit4:junit4] 2> 175238 T544 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372168001518/solr.xml
[junit4:junit4] 2> 175238 T544 oasc.CoreContainer.<init> New CoreContainer 33042990
[junit4:junit4] 2> 175239 T544 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372168001518/'
[junit4:junit4] 2> 175239 T544 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372168001518/'
[junit4:junit4] 2> 175294 T544 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 175295 T544 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 175295 T544 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 175296 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 175296 T544 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 175296 T544 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 175296 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 175297 T544 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 175297 T544 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 175297 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 175301 T544 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 175301 T544 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36043/solr
[junit4:junit4] 2> 175301 T544 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 175302 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 175304 T584 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@793d13 name:ZooKeeperConnection Watcher:127.0.0.1:36043 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 175304 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 175307 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 175310 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 175311 T586 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1968029 name:ZooKeeperConnection Watcher:127.0.0.1:36043/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 175311 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 175315 T544 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 176317 T544 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58748__t
[junit4:junit4] 2> 176319 T544 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58748__t
[junit4:junit4] 2> 176321 T566 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> 176322 T573 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 176322 T586 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 176323 T566 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 176327 T587 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 176327 T587 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 176619 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 176619 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50104__t_collection1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50104__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50104/_t"}
[junit4:junit4] 2> 176622 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:58748__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58748/_t"}
[junit4:junit4] 2> 176622 T567 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 3
[junit4:junit4] 2> 176622 T567 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 176626 T566 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> 176626 T573 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> 176627 T586 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> 177328 T587 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372168001518/collection1
[junit4:junit4] 2> 177328 T587 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 177329 T587 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 177329 T587 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 177330 T587 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372168001518/collection1/'
[junit4:junit4] 2> 177331 T587 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372168001518/collection1/lib/README' to classloader
[junit4:junit4] 2> 177331 T587 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372168001518/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 177365 T587 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 177401 T587 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 177402 T587 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 177406 T587 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 177859 T587 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 177859 T587 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 177860 T587 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 177866 T587 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 177869 T587 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 177880 T587 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 177883 T587 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 177887 T587 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 177888 T587 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 177888 T587 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 177888 T587 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 177889 T587 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 177889 T587 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 177889 T587 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 177889 T587 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372168001518/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty1/
[junit4:junit4] 2> 177890 T587 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d525d2
[junit4:junit4] 2> 177890 T587 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 177890 T587 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty1
[junit4:junit4] 2> 177891 T587 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty1/index/
[junit4:junit4] 2> 177891 T587 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 177892 T587 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty1/index
[junit4:junit4] 2> 177894 T587 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty1/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 177895 T587 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 177896 T587 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 177897 T587 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 177897 T587 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 177898 T587 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 177899 T587 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 177899 T587 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 177899 T587 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 177900 T587 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 177900 T587 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 177903 T587 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 177906 T587 oass.SolrIndexSearcher.<init> Opening Searcher@371c69 main
[junit4:junit4] 2> 177907 T587 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 177907 T587 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 177913 T588 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@371c69 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 177915 T587 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 177915 T587 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58748/_t collection:collection1 shard:shard1
[junit4:junit4] 2> 177916 T587 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 177920 T587 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 177921 T587 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 177922 T587 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 177922 T587 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58748/_t/collection1/
[junit4:junit4] 2> 177922 T587 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 177922 T587 oasc.SyncStrategy.syncToMe http://127.0.0.1:58748/_t/collection1/ has no replicas
[junit4:junit4] 2> 177923 T587 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58748/_t/collection1/
[junit4:junit4] 2> 177923 T587 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 178132 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 178138 T566 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> 178138 T573 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> 178138 T586 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> 178178 T587 oasc.ZkController.register We are http://127.0.0.1:58748/_t/collection1/ and leader is http://127.0.0.1:58748/_t/collection1/
[junit4:junit4] 2> 178178 T587 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58748/_t
[junit4:junit4] 2> 178178 T587 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 178178 T587 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 178179 T587 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 178180 T587 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 178181 T544 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 178182 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 178182 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 178263 T544 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 178265 T544 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:43803
[junit4:junit4] 2> 178265 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 178266 T544 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 178266 T544 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372168004546
[junit4:junit4] 2> 178267 T544 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372168004546/solr.xml
[junit4:junit4] 2> 178267 T544 oasc.CoreContainer.<init> New CoreContainer 5202982
[junit4:junit4] 2> 178267 T544 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372168004546/'
[junit4:junit4] 2> 178268 T544 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372168004546/'
[junit4:junit4] 2> 178323 T544 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 178323 T544 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 178324 T544 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 178324 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 178324 T544 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 178325 T544 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 178325 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 178325 T544 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 178325 T544 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 178326 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 178329 T544 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 178330 T544 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36043/solr
[junit4:junit4] 2> 178330 T544 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 178331 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 178334 T600 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@775869 name:ZooKeeperConnection Watcher:127.0.0.1:36043 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 178335 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 178337 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 178337 T546 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f7b960a790007, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4:junit4] 2>
[junit4:junit4] 2> 178340 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 178341 T602 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@161d48a name:ZooKeeperConnection Watcher:127.0.0.1:36043/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 178342 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 178345 T544 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 179348 T544 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43803__t
[junit4:junit4] 2> 179349 T544 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43803__t
[junit4:junit4] 2> 179351 T566 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> 179352 T586 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 179352 T602 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 179352 T586 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> 179352 T573 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 179353 T573 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> 179353 T566 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 179357 T603 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 179357 T603 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 179642 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 179643 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:58748__t_collection1",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:58748__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58748/_t"}
[junit4:junit4] 2> 179647 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:43803__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:43803/_t"}
[junit4:junit4] 2> 179647 T567 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 179647 T567 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 179651 T566 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> 179651 T573 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> 179651 T602 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> 179651 T586 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> 180358 T603 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372168004546/collection1
[junit4:junit4] 2> 180359 T603 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 180359 T603 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 180359 T603 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 180360 T603 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372168004546/collection1/'
[junit4:junit4] 2> 180361 T603 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372168004546/collection1/lib/README' to classloader
[junit4:junit4] 2> 180361 T603 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372168004546/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 180394 T603 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 180434 T603 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 180436 T603 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 180443 T603 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 180921 T603 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 180922 T603 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 180923 T603 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 180931 T603 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 180935 T603 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 180945 T603 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 180949 T603 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 180954 T603 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 180955 T603 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 180955 T603 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 180955 T603 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 180956 T603 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 180956 T603 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 180956 T603 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 180957 T603 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372168004546/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty2/
[junit4:junit4] 2> 180957 T603 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d525d2
[junit4:junit4] 2> 180958 T603 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 180958 T603 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty2
[junit4:junit4] 2> 180958 T603 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty2/index/
[junit4:junit4] 2> 180959 T603 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 180959 T603 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty2/index
[junit4:junit4] 2> 180963 T603 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty2/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 180963 T603 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 180965 T603 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 180966 T603 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 180966 T603 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 180967 T603 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 180968 T603 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 180968 T603 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 180968 T603 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 180969 T603 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 180969 T603 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 180972 T603 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 180975 T603 oass.SolrIndexSearcher.<init> Opening Searcher@22b6e main
[junit4:junit4] 2> 180976 T603 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 180976 T603 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 180990 T604 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@22b6e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 180993 T603 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 180993 T603 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43803/_t collection:collection1 shard:shard2
[junit4:junit4] 2> 180994 T603 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 180999 T603 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 181001 T603 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 181001 T603 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 181001 T603 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:43803/_t/collection1/
[junit4:junit4] 2> 181002 T603 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 181002 T603 oasc.SyncStrategy.syncToMe http://127.0.0.1:43803/_t/collection1/ has no replicas
[junit4:junit4] 2> 181002 T603 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:43803/_t/collection1/
[junit4:junit4] 2> 181002 T603 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 181157 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 181163 T573 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> 181164 T566 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> 181164 T586 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> 181164 T602 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> 181207 T603 oasc.ZkController.register We are http://127.0.0.1:43803/_t/collection1/ and leader is http://127.0.0.1:43803/_t/collection1/
[junit4:junit4] 2> 181207 T603 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43803/_t
[junit4:junit4] 2> 181208 T603 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 181208 T603 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 181208 T603 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 181210 T603 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 181211 T544 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 181211 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 181212 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 181296 T544 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 181298 T544 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46790
[junit4:junit4] 2> 181299 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 181299 T544 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 181300 T544 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372168007574
[junit4:junit4] 2> 181300 T544 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372168007574/solr.xml
[junit4:junit4] 2> 181300 T544 oasc.CoreContainer.<init> New CoreContainer 27490557
[junit4:junit4] 2> 181300 T544 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372168007574/'
[junit4:junit4] 2> 181301 T544 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372168007574/'
[junit4:junit4] 2> 181365 T544 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 181366 T544 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 181366 T544 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 181367 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 181367 T544 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 181367 T544 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 181368 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 181368 T544 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 181369 T544 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 181369 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 181374 T544 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 181374 T544 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36043/solr
[junit4:junit4] 2> 181375 T544 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 181376 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 181377 T616 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1993ebf name:ZooKeeperConnection Watcher:127.0.0.1:36043 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 181377 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 181382 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 181385 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 181387 T618 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@add293 name:ZooKeeperConnection Watcher:127.0.0.1:36043/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 181387 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 181390 T544 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 182392 T544 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46790__t
[junit4:junit4] 2> 182393 T544 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46790__t
[junit4:junit4] 2> 182395 T566 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> 182396 T618 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 182396 T573 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 182396 T573 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> 182396 T602 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 182396 T586 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 182397 T586 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> 182397 T602 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> 182398 T566 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 182402 T619 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 182402 T619 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 182669 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 182670 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:43803__t_collection1",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:43803__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:43803/_t"}
[junit4:junit4] 2> 182672 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:46790__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:46790/_t"}
[junit4:junit4] 2> 182672 T567 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 182672 T567 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard3
[junit4:junit4] 2> 182676 T586 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> 182676 T618 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> 182676 T573 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> 182676 T602 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> 182676 T566 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> 183404 T619 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372168007574/collection1
[junit4:junit4] 2> 183404 T619 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 183405 T619 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 183405 T619 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 183406 T619 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372168007574/collection1/'
[junit4:junit4] 2> 183407 T619 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372168007574/collection1/lib/README' to classloader
[junit4:junit4] 2> 183407 T619 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372168007574/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 183441 T619 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 183481 T619 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 183483 T619 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 183487 T619 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 183935 T619 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 183935 T619 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 183936 T619 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 183944 T619 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 183947 T619 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 183956 T619 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 183960 T619 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 183963 T619 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 183964 T619 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 183964 T619 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 183964 T619 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 183965 T619 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 183965 T619 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 183965 T619 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 183965 T619 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372168007574/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty3/
[junit4:junit4] 2> 183965 T619 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d525d2
[junit4:junit4] 2> 183966 T619 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 183966 T619 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty3
[junit4:junit4] 2> 183967 T619 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty3/index/
[junit4:junit4] 2> 183967 T619 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 183967 T619 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty3/index
[junit4:junit4] 2> 183970 T619 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty3/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 183970 T619 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 183972 T619 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 183972 T619 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 183972 T619 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 183973 T619 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 183974 T619 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 183974 T619 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 183974 T619 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 183975 T619 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 183975 T619 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 183977 T619 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 183981 T619 oass.SolrIndexSearcher.<init> Opening Searcher@115c2fd main
[junit4:junit4] 2> 183981 T619 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 183981 T619 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 183987 T620 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@115c2fd main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 183990 T619 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 183990 T619 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:46790/_t collection:collection1 shard:shard3
[junit4:junit4] 2> 183991 T619 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4:junit4] 2> 183997 T619 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 184004 T619 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 184004 T619 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 184004 T619 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:46790/_t/collection1/
[junit4:junit4] 2> 184005 T619 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 184005 T619 oasc.SyncStrategy.syncToMe http://127.0.0.1:46790/_t/collection1/ has no replicas
[junit4:junit4] 2> 184005 T619 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:46790/_t/collection1/
[junit4:junit4] 2> 184005 T619 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4:junit4] 2> 184180 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 184186 T586 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> 184186 T602 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> 184186 T566 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> 184186 T573 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> 184186 T618 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> 184210 T619 oasc.ZkController.register We are http://127.0.0.1:46790/_t/collection1/ and leader is http://127.0.0.1:46790/_t/collection1/
[junit4:junit4] 2> 184210 T619 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:46790/_t
[junit4:junit4] 2> 184210 T619 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 184211 T619 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 184211 T619 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 184212 T619 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 184213 T544 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 184213 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 184214 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 184300 T544 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 184301 T544 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57216
[junit4:junit4] 2> 184302 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 184302 T544 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 184303 T544 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372168010576
[junit4:junit4] 2> 184303 T544 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372168010576/solr.xml
[junit4:junit4] 2> 184303 T544 oasc.CoreContainer.<init> New CoreContainer 643220
[junit4:junit4] 2> 184304 T544 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372168010576/'
[junit4:junit4] 2> 184304 T544 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372168010576/'
[junit4:junit4] 2> 184360 T544 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 184360 T544 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 184361 T544 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 184361 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 184361 T544 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 184362 T544 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 184362 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 184362 T544 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 184363 T544 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 184363 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 184366 T544 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 184366 T544 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36043/solr
[junit4:junit4] 2> 184367 T544 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 184368 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 184369 T632 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a95ae name:ZooKeeperConnection Watcher:127.0.0.1:36043 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 184370 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 184372 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 184376 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 184377 T634 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e21b11 name:ZooKeeperConnection Watcher:127.0.0.1:36043/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 184377 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 184381 T544 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 185384 T544 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57216__t
[junit4:junit4] 2> 185385 T544 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57216__t
[junit4:junit4] 2> 185387 T566 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> 185387 T586 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 185387 T586 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> 185387 T602 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 185388 T602 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> 185388 T634 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 185388 T618 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> 185388 T573 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 185389 T573 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> 185389 T566 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 185390 T618 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 185394 T635 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 185394 T635 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 185691 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 185691 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:46790__t_collection1",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard3",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:46790__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:46790/_t"}
[junit4:junit4] 2> 185694 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57216__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57216/_t"}
[junit4:junit4] 2> 185694 T567 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 185694 T567 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 185697 T573 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> 185698 T602 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> 185698 T586 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> 185698 T566 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> 185698 T634 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> 185697 T618 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> 186396 T635 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372168010576/collection1
[junit4:junit4] 2> 186396 T635 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 186397 T635 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 186397 T635 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 186398 T635 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372168010576/collection1/'
[junit4:junit4] 2> 186399 T635 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372168010576/collection1/lib/README' to classloader
[junit4:junit4] 2> 186399 T635 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372168010576/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 186437 T635 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 186479 T635 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 186480 T635 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 186486 T635 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 186915 T635 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 186916 T635 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 186916 T635 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 186922 T635 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 186925 T635 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 186934 T635 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 186939 T635 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 186944 T635 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 186945 T635 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 186945 T635 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 186945 T635 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 186946 T635 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 186947 T635 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 186947 T635 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 186947 T635 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372168010576/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty4/
[junit4:junit4] 2> 186948 T635 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d525d2
[junit4:junit4] 2> 186948 T635 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 186949 T635 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty4
[junit4:junit4] 2> 186949 T635 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty4/index/
[junit4:junit4] 2> 186949 T635 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 186950 T635 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty4/index
[junit4:junit4] 2> 186953 T635 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty4/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 186954 T635 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 186956 T635 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 186956 T635 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 186957 T635 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 186958 T635 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 186959 T635 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 186959 T635 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 186960 T635 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 186961 T635 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 186961 T635 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 186965 T635 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 186972 T635 oass.SolrIndexSearcher.<init> Opening Searcher@d08573 main
[junit4:junit4] 2> 186973 T635 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 186973 T635 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 186980 T636 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d08573 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 186982 T635 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 186982 T635 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57216/_t collection:collection1 shard:shard1
[junit4:junit4] 2> 186985 T635 oasc.ZkController.register We are http://127.0.0.1:57216/_t/collection1/ and leader is http://127.0.0.1:58748/_t/collection1/
[junit4:junit4] 2> 186986 T635 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57216/_t
[junit4:junit4] 2> 186986 T635 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 186986 T635 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C174 name=collection1 org.apache.solr.core.SolrCore@16ebdfb url=http://127.0.0.1:57216/_t/collection1 node=127.0.0.1:57216__t C174_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:57216__t, base_url=http://127.0.0.1:57216/_t}
[junit4:junit4] 2> 186987 T637 C174 P57216 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 186987 T635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 186988 T637 C174 P57216 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 186988 T637 C174 P57216 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 186988 T637 C174 P57216 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 186988 T544 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 186989 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 186989 T637 C174 P57216 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 186989 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 186994 T576 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:57216__t_collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 187075 T544 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 187077 T544 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36377
[junit4:junit4] 2> 187078 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 187078 T544 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 187078 T544 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372168013352
[junit4:junit4] 2> 187079 T544 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372168013352/solr.xml
[junit4:junit4] 2> 187079 T544 oasc.CoreContainer.<init> New CoreContainer 3249677
[junit4:junit4] 2> 187079 T544 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372168013352/'
[junit4:junit4] 2> 187080 T544 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372168013352/'
[junit4:junit4] 2> 187145 T544 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 187145 T544 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 187146 T544 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 187146 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 187147 T544 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 187147 T544 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 187147 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 187148 T544 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 187148 T544 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 187149 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 187153 T544 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 187154 T544 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36043/solr
[junit4:junit4] 2> 187154 T544 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 187155 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 187157 T649 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1570c5 name:ZooKeeperConnection Watcher:127.0.0.1:36043 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 187157 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 187159 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 187162 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 187163 T651 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17b4ee5 name:ZooKeeperConnection Watcher:127.0.0.1:36043/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 187163 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 187166 T544 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 187203 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 187205 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:57216__t_collection1",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57216__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57216/_t"}
[junit4:junit4] 2> 187209 T634 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> 187209 T602 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> 187210 T586 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> 187209 T651 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> 187209 T618 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> 187210 T566 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> 187210 T573 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> 187995 T576 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:57216__t_collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 187996 T576 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:57216__t_collection1&state=recovering&nodeName=127.0.0.1:57216__t&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1002
[junit4:junit4] 2> 188169 T544 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36377__t
[junit4:junit4] 2> 188170 T544 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36377__t
[junit4:junit4] 2> 188172 T618 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> 188172 T566 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> 188172 T586 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 188173 T573 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 188173 T634 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 188173 T602 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 188173 T602 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> 188173 T634 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> 188173 T573 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> 188174 T618 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 188173 T651 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 188174 T651 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> 188173 T586 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> 188174 T566 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 188179 T652 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 188179 T652 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 188714 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 188714 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:36377__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36377/_t"}
[junit4:junit4] 2> 188715 T567 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 188715 T567 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 188719 T634 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> 188719 T573 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> 188719 T602 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> 188719 T566 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> 188719 T586 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> 188719 T651 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> 188719 T618 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> 189181 T652 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372168013352/collection1
[junit4:junit4] 2> 189181 T652 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 189182 T652 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 189182 T652 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 189183 T652 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372168013352/collection1/'
[junit4:junit4] 2> 189184 T652 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372168013352/collection1/lib/README' to classloader
[junit4:junit4] 2> 189184 T652 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372168013352/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 189229 T652 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 189282 T652 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 189284 T652 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 189288 T652 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 189660 T652 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 189661 T652 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 189661 T652 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 189667 T652 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 189670 T652 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 189679 T652 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 189682 T652 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 189684 T652 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 189685 T652 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 189685 T652 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 189685 T652 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 189686 T652 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 189686 T652 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 189687 T652 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 189687 T652 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372168013352/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty5/
[junit4:junit4] 2> 189687 T652 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d525d2
[junit4:junit4] 2> 189687 T652 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 189688 T652 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty5
[junit4:junit4] 2> 189688 T652 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty5/index/
[junit4:junit4] 2> 189688 T652 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty5/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 189688 T652 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty5/index
[junit4:junit4] 2> 189716 T652 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty5/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 189716 T652 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 189718 T652 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 189718 T652 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 189719 T652 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 189719 T652 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 189720 T652 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 189720 T652 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 189720 T652 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 189721 T652 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 189721 T652 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 189723 T652 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 189726 T652 oass.SolrIndexSearcher.<init> Opening Searcher@1a212d7 main
[junit4:junit4] 2> 189726 T652 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 189727 T652 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 189733 T653 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1a212d7 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 189735 T652 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 189735 T652 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36377/_t collection:collection1 shard:shard2
[junit4:junit4] 2> 189738 T652 oasc.ZkController.register We are http://127.0.0.1:36377/_t/collection1/ and leader is http://127.0.0.1:43803/_t/collection1/
[junit4:junit4] 2> 189738 T652 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36377/_t
[junit4:junit4] 2> 189738 T652 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 189738 T652 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C175 name=collection1 org.apache.solr.core.SolrCore@1067209 url=http://127.0.0.1:36377/_t/collection1 node=127.0.0.1:36377__t C175_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:36377__t, base_url=http://127.0.0.1:36377/_t}
[junit4:junit4] 2> 189738 T654 C175 P36377 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 189739 T652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 189739 T654 C175 P36377 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 189740 T654 C175 P36377 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 189740 T654 C175 P36377 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 189741 T544 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 189741 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 189741 T654 C175 P36377 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 189742 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 189745 T597 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:36377__t_collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 189811 T544 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 189813 T544 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56324
[junit4:junit4] 2> 189814 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 189814 T544 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 189814 T544 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372168016108
[junit4:junit4] 2> 189815 T544 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372168016108/solr.xml
[junit4:junit4] 2> 189815 T544 oasc.CoreContainer.<init> New CoreContainer 1658486
[junit4:junit4] 2> 189815 T544 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372168016108/'
[junit4:junit4] 2> 189815 T544 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372168016108/'
[junit4:junit4] 2> 189863 T544 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 189863 T544 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 189863 T544 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 189864 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 189864 T544 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 189864 T544 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 189864 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 189865 T544 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 189865 T544 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 189865 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 189868 T544 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 189869 T544 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36043/solr
[junit4:junit4] 2> 189869 T544 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 189870 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 189871 T666 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14d8483 name:ZooKeeperConnection Watcher:127.0.0.1:36043 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 189872 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 189873 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 189876 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 189877 T668 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14609c5 name:ZooKeeperConnection Watcher:127.0.0.1:36043/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 189877 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 189880 T544 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C176 name=collection1 org.apache.solr.core.SolrCore@16ebdfb url=http://127.0.0.1:57216/_t/collection1 node=127.0.0.1:57216__t C176_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:57216__t, base_url=http://127.0.0.1:57216/_t}
[junit4:junit4] 2> 189996 T637 C176 P57216 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:58748/_t/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 189997 T637 C176 P57216 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:57216/_t START replicas=[http://127.0.0.1:58748/_t/collection1/] nUpdates=100
[junit4:junit4] 2> 189997 T637 C176 P57216 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 189997 T637 C176 P57216 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 189998 T637 C176 P57216 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 189998 T637 C176 P57216 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 189998 T637 C176 P57216 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 189998 T637 C176 P57216 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:58748/_t/collection1/. core=collection1
[junit4:junit4] 2> 189998 T637 C176 P57216 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C177 name=collection1 org.apache.solr.core.SolrCore@1c5f2 url=http://127.0.0.1:58748/_t/collection1 node=127.0.0.1:58748__t C177_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:58748__t, base_url=http://127.0.0.1:58748/_t, leader=true}
[junit4:junit4] 2> 190011 T580 C177 P58748 oasc.SolrCore.execute [collection1] webapp=/_t path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 190015 T576 C177 P58748 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 190017 T576 C177 P58748 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty1/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 190017 T576 C177 P58748 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 190022 T576 C177 P58748 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty1/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty1/index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 190022 T576 C177 P58748 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 190023 T576 C177 P58748 oass.SolrIndexSearcher.<init> Opening Searcher@3cfced realtime
[junit4:junit4] 2> 190023 T576 C177 P58748 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 190024 T576 C177 P58748 oasup.LogUpdateProcessor.finish [collection1] webapp=/_t path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 9
[junit4:junit4] 2> ASYNC NEW_CORE C178 name=collection1 org.apache.solr.core.SolrCore@16ebdfb url=http://127.0.0.1:57216/_t/collection1 node=127.0.0.1:57216__t C178_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:57216__t, base_url=http://127.0.0.1:57216/_t}
[junit4:junit4] 2> 190024 T637 C178 P57216 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 190024 T637 C178 P57216 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 190026 T582 C177 P58748 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 190026 T582 C177 P58748 oasc.SolrCore.execute [collection1] webapp=/_t path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 190027 T637 C178 P57216 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 190027 T637 C178 P57216 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 190027 T637 C178 P57216 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 190029 T580 C177 P58748 oasc.SolrCore.execute [collection1] webapp=/_t path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 190030 T637 C178 P57216 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 190030 T637 C178 P57216 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty4/index.20130625074656389
[junit4:junit4] 2> 190030 T637 C178 P57216 oash.SnapPuller.fetchLatestIndex Starting download to org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty4/index.20130625074656389 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9539b0 fullCopy=false
[junit4:junit4] 2> 190033 T576 C177 P58748 oasc.SolrCore.execute [collection1] webapp=/_t path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1
[junit4:junit4] 2> 190034 T637 C178 P57216 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 190043 T637 C178 P57216 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 190043 T637 C178 P57216 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 190044 T637 C178 P57216 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty4/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty4/index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 190045 T637 C178 P57216 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 190045 T637 C178 P57216 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 190046 T637 C178 P57216 oass.SolrIndexSearcher.<init> Opening Searcher@ff42fe main
[junit4:junit4] 2> 190047 T636 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ff42fe main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 190048 T637 C178 P57216 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty4/index.20130625074656389 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty4/index.20130625074656389;done=true>>]
[junit4:junit4] 2> 190048 T637 C178 P57216 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty4/index.20130625074656389
[junit4:junit4] 2> 190048 T637 C178 P57216 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty4/index.20130625074656389
[junit4:junit4] 2> 190051 T637 C178 P57216 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 190051 T637 C178 P57216 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 190051 T637 C178 P57216 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 190051 T637 C178 P57216 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 190053 T637 C178 P57216 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 190224 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 190225 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:36377__t_collection1",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:36377__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36377/_t"}
[junit4:junit4] 2> 190228 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:57216__t_collection1",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57216__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57216/_t"}
[junit4:junit4] 2> 190242 T634 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> 190242 T573 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> 190242 T586 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> 190242 T618 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> 190242 T602 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> 190242 T668 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> 190243 T566 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> 190243 T651 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> 190747 T597 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:36377__t_collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 190748 T597 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:36377__t_collection1&state=recovering&nodeName=127.0.0.1:36377__t&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1003
[junit4:junit4] 2> 190882 T544 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56324__t
[junit4:junit4] 2> 190883 T544 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56324__t
[junit4:junit4] 2> 190885 T668 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> 190885 T566 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> 190885 T618 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> 190886 T573 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 190886 T651 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 190886 T651 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> 190886 T602 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 190886 T586 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 190887 T586 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> 190886 T573 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> 190886 T634 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 190887 T618 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 190888 T566 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 190887 T668 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 190887 T602 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> 190888 T634 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> 190892 T671 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 190893 T671 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 191750 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 191751 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:56324__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:56324/_t"}
[junit4:junit4] 2> 191751 T567 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 191751 T567 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard3
[junit4:junit4] 2> 191754 T634 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> 191754 T586 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> 191754 T618 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> 191754 T602 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> 191754 T566 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> 191754 T573 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> 191754 T651 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> 191754 T668 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> 191894 T671 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372168016108/collection1
[junit4:junit4] 2> 191894 T671 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 191895 T671 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 191895 T671 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 191896 T671 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372168016108/collection1/'
[junit4:junit4] 2> 191896 T671 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372168016108/collection1/lib/README' to classloader
[junit4:junit4] 2> 191897 T671 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372168016108/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 191932 T671 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 191970 T671 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 191972 T671 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 191976 T671 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 192379 T671 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 192379 T671 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 192380 T671 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 192386 T671 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 192390 T671 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 192399 T671 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 192402 T671 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 192405 T671 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 192406 T671 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 192406 T671 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 192406 T671 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 192407 T671 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 192407 T671 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 192407 T671 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 192407 T671 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372168016108/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty6/
[junit4:junit4] 2> 192408 T671 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d525d2
[junit4:junit4] 2> 192408 T671 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 192408 T671 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty6
[junit4:junit4] 2> 192409 T671 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty6/index/
[junit4:junit4] 2> 192409 T671 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty6/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 192409 T671 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty6/index
[junit4:junit4] 2> 192494 T671 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty6/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 192494 T671 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 192495 T671 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 192496 T671 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 192496 T671 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 192497 T671 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 192497 T671 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 192497 T671 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 192498 T671 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 192498 T671 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 192499 T671 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 192501 T671 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 192504 T671 oass.SolrIndexSearcher.<init> Opening Searcher@b00d91 main
[junit4:junit4] 2> 192504 T671 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 192505 T671 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 192510 T672 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b00d91 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 192512 T671 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 192512 T671 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56324/_t collection:collection1 shard:shard3
[junit4:junit4] 2> 192515 T671 oasc.ZkController.register We are http://127.0.0.1:56324/_t/collection1/ and leader is http://127.0.0.1:46790/_t/collection1/
[junit4:junit4] 2> 192515 T671 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56324/_t
[junit4:junit4] 2> 192515 T671 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 192516 T671 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C179 name=collection1 org.apache.solr.core.SolrCore@c51d92 url=http://127.0.0.1:56324/_t/collection1 node=127.0.0.1:56324__t C179_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:56324__t, base_url=http://127.0.0.1:56324/_t}
[junit4:junit4] 2> 192516 T673 C179 P56324 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 192516 T671 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 192517 T673 C179 P56324 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 192517 T673 C179 P56324 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 192517 T673 C179 P56324 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 192518 T544 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 192518 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 192518 T673 C179 P56324 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 192518 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 192522 T611 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:56324__t_collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 192598 T544 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 192600 T544 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60777
[junit4:junit4] 2> 192601 T544 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 192601 T544 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 192601 T544 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372168018881
[junit4:junit4] 2> 192602 T544 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372168018881/solr.xml
[junit4:junit4] 2> 192602 T544 oasc.CoreContainer.<init> New CoreContainer 30390850
[junit4:junit4] 2> 192602 T544 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372168018881/'
[junit4:junit4] 2> 192603 T544 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372168018881/'
[junit4:junit4] 2> 192666 T544 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 192667 T544 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 192667 T544 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 192667 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 192668 T544 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 192668 T544 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 192668 T544 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 192669 T544 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 192669 T544 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 192669 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 192672 T544 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 192673 T544 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36043/solr
[junit4:junit4] 2> 192673 T544 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 192674 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 192676 T685 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9bdb15 name:ZooKeeperConnection Watcher:127.0.0.1:36043 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 192676 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 192678 T544 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 192681 T544 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 192682 T687 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fa2475 name:ZooKeeperConnection Watcher:127.0.0.1:36043/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 192682 T544 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 192685 T544 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C180 name=collection1 org.apache.solr.core.SolrCore@1067209 url=http://127.0.0.1:36377/_t/collection1 node=127.0.0.1:36377__t C180_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:36377__t, base_url=http://127.0.0.1:36377/_t}
[junit4:junit4] 2> 192748 T654 C180 P36377 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:43803/_t/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 192749 T654 C180 P36377 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:36377/_t START replicas=[http://127.0.0.1:43803/_t/collection1/] nUpdates=100
[junit4:junit4] 2> 192749 T654 C180 P36377 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 192749 T654 C180 P36377 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 192749 T654 C180 P36377 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 192750 T654 C180 P36377 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 192750 T654 C180 P36377 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 192750 T654 C180 P36377 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:43803/_t/collection1/. core=collection1
[junit4:junit4] 2> 192750 T654 C180 P36377 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C181 name=collection1 org.apache.solr.core.SolrCore@1f8647f url=http://127.0.0.1:43803/_t/collection1 node=127.0.0.1:43803__t C181_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:43803__t, base_url=http://127.0.0.1:43803/_t, leader=true}
[junit4:junit4] 2> 192755 T598 C181 P43803 oasc.SolrCore.execute [collection1] webapp=/_t path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 192759 T593 C181 P43803 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 192761 T593 C181 P43803 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty2/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 192761 T593 C181 P43803 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 192792 T593 C181 P43803 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty2/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty2/index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 192793 T593 C181 P43803 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 192793 T593 C181 P43803 oass.SolrIndexSearcher.<init> Opening Searcher@5d03e6 realtime
[junit4:junit4] 2> 192793 T593 C181 P43803 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 192794 T593 C181 P43803 oasup.LogUpdateProcessor.finish [collection1] webapp=/_t path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 35
[junit4:junit4] 2> 192795 T654 C180 P36377 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 192795 T654 C180 P36377 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 192796 T596 C181 P43803 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 192796 T596 C181 P43803 oasc.SolrCore.execute [collection1] webapp=/_t path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 192797 T654 C180 P36377 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 192797 T654 C180 P36377 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 192797 T654 C180 P36377 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 192799 T598 C181 P43803 oasc.SolrCore.execute [collection1] webapp=/_t path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 192799 T654 C180 P36377 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 192800 T654 C180 P36377 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty5/index.20130625074659158
[junit4:junit4] 2> 192800 T654 C180 P36377 oash.SnapPuller.fetchLatestIndex Starting download to org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty5/index.20130625074659158 lockFactory=org.apache.lucene.store.NativeFSLockFactory@f01565 fullCopy=false
[junit4:junit4] 2> 192802 T593 C181 P43803 oasc.SolrCore.execute [collection1] webapp=/_t path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 192803 T654 C180 P36377 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 192813 T654 C180 P36377 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 192813 T654 C180 P36377 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 192814 T654 C180 P36377 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty5/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty5/index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 192814 T654 C180 P36377 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 192815 T654 C180 P36377 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 192815 T654 C180 P36377 oass.SolrIndexSearcher.<init> Opening Searcher@1e89ee3 main
[junit4:junit4] 2> 192816 T653 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e89ee3 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 192817 T654 C180 P36377 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty5/index.20130625074659158 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty5/index.20130625074659158;done=true>>]
[junit4:junit4] 2> 192817 T654 C180 P36377 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty5/index.20130625074659158
[junit4:junit4] 2> 192817 T654 C180 P36377 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty5/index.20130625074659158
[junit4:junit4] 2> 192817 T654 C180 P36377 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 192817 T654 C180 P36377 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 192818 T654 C180 P36377 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 192818 T654 C180 P36377 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 192820 T654 C180 P36377 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 193258 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 193259 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:56324__t_collection1",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard3",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:56324__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:56324/_t"}
[junit4:junit4] 2> 193262 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:36377__t_collection1",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:36377__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36377/_t"}
[junit4:junit4] 2> 193302 T668 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> 193303 T573 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> 193303 T602 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> 193303 T566 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> 193303 T651 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> 193302 T586 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> 193302 T687 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> 193303 T634 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> 193302 T618 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> 193523 T611 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:56324__t_collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 193523 T611 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:56324__t_collection1&state=recovering&nodeName=127.0.0.1:56324__t&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1001
[junit4:junit4] 2> 193687 T544 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60777__t
[junit4:junit4] 2> 193689 T544 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60777__t
[junit4:junit4] 2> 193691 T687 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> 193691 T668 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> 193691 T634 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 193691 T602 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 193692 T573 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 193691 T618 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> 193692 T573 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> 193692 T602 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> 193691 T634 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> 193691 T566 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> 193693 T668 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 193691 T651 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 193691 T586 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 193694 T586 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> 193694 T618 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 193693 T651 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> 193693 T687 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 193696 T566 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 193700 T690 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 193700 T690 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 194810 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 194811 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:60777__t",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:60777/_t"}
[junit4:junit4] 2> 194811 T567 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 194811 T567 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 194892 T668 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> 194893 T602 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> 194893 T651 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> 194893 T566 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> 194893 T687 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> 194893 T586 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> 194893 T634 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> 194893 T573 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> 194892 T618 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> ASYNC NEW_CORE C182 name=collection1 org.apache.solr.core.SolrCore@c51d92 url=http://127.0.0.1:56324/_t/collection1 node=127.0.0.1:56324__t C182_STATE=coll:collection1 core:collection1 props:{shard=shard3, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:56324__t, base_url=http://127.0.0.1:56324/_t}
[junit4:junit4] 2> 195524 T673 C182 P56324 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:46790/_t/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 195524 T673 C182 P56324 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:56324/_t START replicas=[http://127.0.0.1:46790/_t/collection1/] nUpdates=100
[junit4:junit4] 2> 195525 T673 C182 P56324 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 195525 T673 C182 P56324 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 195525 T673 C182 P56324 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 195526 T673 C182 P56324 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 195526 T673 C182 P56324 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 195526 T673 C182 P56324 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:46790/_t/collection1/. core=collection1
[junit4:junit4] 2> 195526 T673 C182 P56324 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C183 name=collection1 org.apache.solr.core.SolrCore@1443dcb url=http://127.0.0.1:46790/_t/collection1 node=127.0.0.1:46790__t C183_STATE=coll:collection1 core:collection1 props:{shard=shard3, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:46790__t, base_url=http://127.0.0.1:46790/_t, leader=true}
[junit4:junit4] 2> 195530 T611 C183 P46790 oasc.SolrCore.execute [collection1] webapp=/_t path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 195531 T613 C183 P46790 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 195533 T613 C183 P46790 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty3/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 195533 T613 C183 P46790 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 195622 T613 C183 P46790 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty3/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty3/index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 195623 T613 C183 P46790 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 195623 T613 C183 P46790 oass.SolrIndexSearcher.<init> Opening Searcher@1b6c0f5 realtime
[junit4:junit4] 2> 195623 T613 C183 P46790 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 195624 T613 C183 P46790 oasup.LogUpdateProcessor.finish [collection1] webapp=/_t path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 93
[junit4:junit4] 2> 195624 T673 C182 P56324 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 195625 T673 C182 P56324 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 195626 T611 C183 P46790 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 195627 T611 C183 P46790 oasc.SolrCore.execute [collection1] webapp=/_t path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 195627 T673 C182 P56324 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 195627 T673 C182 P56324 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 195628 T673 C182 P56324 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 195630 T612 C183 P46790 oasc.SolrCore.execute [collection1] webapp=/_t path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4:junit4] 2> 195630 T673 C182 P56324 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 195631 T673 C182 P56324 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty6/index.20130625074701989
[junit4:junit4] 2> 195631 T673 C182 P56324 oash.SnapPuller.fetchLatestIndex Starting download to org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty6/index.20130625074701989 lockFactory=org.apache.lucene.store.NativeFSLockFactory@34b8fd fullCopy=false
[junit4:junit4] 2> 195633 T613 C183 P46790 oasc.SolrCore.execute [collection1] webapp=/_t path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 195634 T673 C182 P56324 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 195643 T673 C182 P56324 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 195643 T673 C182 P56324 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 195644 T673 C182 P56324 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty6/index,segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty6/index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 195645 T673 C182 P56324 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 195645 T673 C182 P56324 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 195645 T673 C182 P56324 oass.SolrIndexSearcher.<init> Opening Searcher@726961 main
[junit4:junit4] 2> 195647 T672 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@726961 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 195647 T673 C182 P56324 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty6/index.20130625074701989 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty6/index.20130625074701989;done=true>>]
[junit4:junit4] 2> 195648 T673 C182 P56324 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty6/index.20130625074701989
[junit4:junit4] 2> 195648 T673 C182 P56324 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372167998070/jetty6/index.20130625074701989
[junit4:junit4] 2> 195648 T673 C182 P56324 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 195648 T673 C182 P56324 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 19
[...truncated too long message...]
failure: Error opening new searcher
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([940F15D1FF7BA1C1]:0)
[junit4:junit4] > at org.apache.solr.core.CoreContainer.getCore(CoreContainer.java:970)
[junit4:junit4] > at org.apache.solr.handler.admin.CoreAdminHandler$2.run(CoreAdminHandler.java:795)
[junit4:junit4] > Caused by: org.apache.solr.common.SolrException: Error opening new searcher
[junit4:junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:835)
[junit4:junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:627)
[junit4:junit4] > at org.apache.solr.core.ZkContainer.createFromZk(ZkContainer.java:264)
[junit4:junit4] > at org.apache.solr.core.CoreContainer.create(CoreContainer.java:764)
[junit4:junit4] > at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:437)
[junit4:junit4] > at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:429)
[junit4:junit4] > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4] > at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4] > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4:junit4] > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4] > at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4:junit4] > Caused by: org.apache.solr.common.SolrException: Error opening new searcher
[junit4:junit4] > at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1512)
[junit4:junit4] > at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1624)
[junit4:junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:810)
[junit4:junit4] > ... 13 more
[junit4:junit4] > Caused by: org.apache.solr.common.SolrException: Error opening Reader
[junit4:junit4] > at org.apache.solr.search.SolrIndexSearcher.getReader(SolrIndexSearcher.java:173)
[junit4:junit4] > at org.apache.solr.search.SolrIndexSearcher.<init>(SolrIndexSearcher.java:184)
[junit4:junit4] > at org.apache.solr.search.SolrIndexSearcher.<init>(SolrIndexSearcher.java:180)
[junit4:junit4] > at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1487)
[junit4:junit4] > ... 15 more
[junit4:junit4] > Caused by: java.lang.AssertionError: liveDocs.count()=15 info.docCount=20 info.getDelCount()=12
[junit4:junit4] > at org.apache.lucene.codecs.lucene40.Lucene40LiveDocsFormat.readLiveDocs(Lucene40LiveDocsFormat.java:92)
[junit4:junit4] > at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:61)
[junit4:junit4] > at org.apache.lucene.index.StandardDirectoryReader$1.doBody(StandardDirectoryReader.java:62)
[junit4:junit4] > at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:812)
[junit4:junit4] > at org.apache.lucene.index.StandardDirectoryReader.open(StandardDirectoryReader.java:52)
[junit4:junit4] > at org.apache.lucene.index.DirectoryReader.open(DirectoryReader.java:88)
[junit4:junit4] > at org.apache.solr.core.StandardIndexReaderFactory.newReader(StandardIndexReaderFactory.java:34)
[junit4:junit4] > at org.apache.solr.search.SolrIndexSearcher.getReader(SolrIndexSearcher.java:170)
[junit4:junit4] > ... 18 moreThrowable #6: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=847, name=Thread-397, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4] > Caused by: org.apache.solr.common.SolrException: SolrCore 'collection1' is not available due to init failure: Error opening new searcher
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([940F15D1FF7BA1C1]:0)
[junit4:junit4] > at org.apache.solr.core.CoreContainer.getCore(CoreContainer.java:970)
[junit4:junit4] > at org.apache.solr.handler.admin.CoreAdminHandler$2.run(CoreAdminHandler.java:795)
[junit4:junit4] > Caused by: org.apache.solr.common.SolrException: Error opening new searcher
[junit4:junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:835)
[junit4:junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:627)
[junit4:junit4] > at org.apache.solr.core.ZkContainer.createFromZk(ZkContainer.java:264)
[junit4:junit4] > at org.apache.solr.core.CoreContainer.create(CoreContainer.java:764)
[junit4:junit4] > at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:437)
[junit4:junit4] > at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:429)
[junit4:junit4] > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4] > at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4] > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4:junit4] > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4] > at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4:junit4] > Caused by: org.apache.solr.common.SolrException: Error opening new searcher
[junit4:junit4] > at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1512)
[junit4:junit4] > at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1624)
[junit4:junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:810)
[junit4:junit4] > ... 13 more
[junit4:junit4] > Caused by: org.apache.solr.common.SolrException: Error opening Reader
[junit4:junit4] > at org.apache.solr.search.SolrIndexSearcher.getReader(SolrIndexSearcher.java:173)
[junit4:junit4] > at org.apache.solr.search.SolrIndexSearcher.<init>(SolrIndexSearcher.java:184)
[junit4:junit4] > at org.apache.solr.search.SolrIndexSearcher.<init>(SolrIndexSearcher.java:180)
[junit4:junit4] > at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1487)
[junit4:junit4] > ... 15 more
[junit4:junit4] > Caused by: java.lang.AssertionError: liveDocs.count()=15 info.docCount=20 info.getDelCount()=12
[junit4:junit4] > at org.apache.lucene.codecs.lucene40.Lucene40LiveDocsFormat.readLiveDocs(Lucene40LiveDocsFormat.java:92)
[junit4:junit4] > at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:61)
[junit4:junit4] > at org.apache.lucene.index.StandardDirectoryReader$1.doBody(StandardDirectoryReader.java:62)
[junit4:junit4] > at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:812)
[junit4:junit4] > at org.apache.lucene.index.StandardDirectoryReader.open(StandardDirectoryReader.java:52)
[junit4:junit4] > at org.apache.lucene.index.DirectoryReader.open(DirectoryReader.java:88)
[junit4:junit4] > at org.apache.solr.core.StandardIndexReaderFactory.newReader(StandardIndexReaderFactory.java:34)
[junit4:junit4] > at org.apache.solr.search.SolrIndexSearcher.getReader(SolrIndexSearcher.java:170)
[junit4:junit4] > ... 18 more
[junit4:junit4] 2> 260958 T544 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 89257 T543 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4] 2> NOTE: test params are: codec=FastDecompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=263), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=263)), sim=DefaultSimilarity, locale=in_ID, timezone=America/El_Salvador
[junit4:junit4] 2> NOTE: Linux 3.2.0-48-generic i386/Oracle Corporation 1.7.0_25 (32-bit)/cpus=8,threads=2,free=105282512,total=237568000
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestRTGBase, ClusterStateTest, HighlighterTest, BasicDistributedZk2Test, NumericFieldsTest, DOMUtilTest, JSONWriterTest, SuggesterWFSTTest, DirectSolrSpellCheckerTest, TestReload, CurrencyFieldXmlFileTest, StandardRequestHandlerTest, TestRangeQuery, CopyFieldTest, SampleTest, TestNumberUtils, FileUtilsTest, EchoParamsTest, StatsComponentTest, DirectUpdateHandlerTest, TestDistributedGrouping, OutputWriterTest, ChaosMonkeySafeLeaderTest]
[junit4:junit4] Completed on J1 in 90.06s, 1 test, 1 error <<< FAILURES!
[...truncated 780 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:392: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:372: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:437: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1246: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:890: There were test failures: 298 suites, 1256 tests, 1 error, 13 ignored (7 assumptions)
Total time: 38 minutes 33 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_25 -client -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure