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 2014/01/15 22:29:03 UTC
[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0-ea-b123) - Build
# 9106 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9106/
Java: 64bit/jdk1.8.0-ea-b123 -XX:+UseCompressedOops -XX:+UseSerialGC
3 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
Error Message:
Suite timeout exceeded (>= 7200000 msec).
Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
at __randomizedtesting.SeedInfo.seed([D4BF55D80BE0B97D]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
Error Message:
Captured an uncaught exception in thread: Thread[id=3397, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=3397, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
Caused by: java.lang.AssertionError: liveDocs.count()=15 info.docCount=30 info.getDelCount()=19
at __randomizedtesting.SeedInfo.seed([D4BF55D80BE0B97D]:0)
at org.apache.lucene.codecs.lucene40.Lucene40LiveDocsFormat.readLiveDocs(Lucene40LiveDocsFormat.java:92)
at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:103)
at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:131)
at org.apache.lucene.index.ReadersAndUpdates.getReadOnlyClone(ReadersAndUpdates.java:183)
at org.apache.lucene.index.StandardDirectoryReader.open(StandardDirectoryReader.java:97)
at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:380)
at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:268)
at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:204)
at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1444)
at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1632)
at org.apache.solr.handler.SnapPuller.openNewSearcherAndUpdateCommitPoint(SnapPuller.java:670)
at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:490)
at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:322)
at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:155)
at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:437)
at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:247)
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
Test abandoned because suite timeout was reached.
Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
at __randomizedtesting.SeedInfo.seed([D4BF55D80BE0B97D]:0)
Build Log:
[...truncated 11068 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4] 2> 391784 T2997 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 391786 T2997 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-ChaosMonkeySafeLeaderTest-1389814081183
[junit4] 2> 391787 T2997 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 391788 T2998 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 391888 T2997 oasc.ZkTestServer.run start zk server on port:35649
[junit4] 2> 391889 T2997 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 392017 T3004 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42ee8b78 name:ZooKeeperConnection Watcher:127.0.0.1:35649 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 392018 T2997 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 392018 T2997 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 392023 T2997 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 392024 T3006 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1346e78 name:ZooKeeperConnection Watcher:127.0.0.1:35649/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 392024 T2997 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 392024 T2997 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 392026 T2997 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 392028 T2997 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 392029 T2997 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 392031 T2997 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 392032 T2997 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 392039 T2997 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 392039 T2997 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 392043 T2997 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 392044 T2997 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 392047 T2997 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 392047 T2997 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 392050 T2997 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 392051 T2997 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 392054 T2997 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 392055 T2997 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 392058 T2997 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 392058 T2997 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 392062 T2997 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 392063 T2997 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 392065 T2997 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 392066 T2997 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 392069 T2997 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 392070 T2997 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 392073 T2997 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 392074 T2997 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 392148 T2997 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 392153 T2997 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:59181
[junit4] 2> 392153 T2997 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 392154 T2997 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 392154 T2997 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1389814081474
[junit4] 2> 392154 T2997 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1389814081474/'
[junit4] 2> 392172 T2997 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1389814081474/solr.xml
[junit4] 2> 392179 T2997 oasc.CoreContainer.<init> New CoreContainer 1565835876
[junit4] 2> 392179 T2997 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1389814081474/]
[junit4] 2> 392179 T2997 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 392180 T2997 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 392180 T2997 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 392180 T2997 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 392180 T2997 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 392180 T2997 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 392181 T2997 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 392181 T2997 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 392181 T2997 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 392183 T2997 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 392183 T2997 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 392183 T2997 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 392184 T2997 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:35649/solr
[junit4] 2> 392184 T2997 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 392184 T2997 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 392186 T3017 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b169c60 name:ZooKeeperConnection Watcher:127.0.0.1:35649 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 392186 T2997 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 392187 T2997 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 392188 T3019 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@223f2828 name:ZooKeeperConnection Watcher:127.0.0.1:35649/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 392188 T2997 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 392190 T2997 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 392192 T2997 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 392199 T2997 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 392201 T2997 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59181_
[junit4] 2> 392202 T2997 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59181_
[junit4] 2> 392204 T2997 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 392206 T2997 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 392208 T2997 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 392210 T2997 oasc.Overseer.start Overseer (id=91082855624605699-127.0.0.1:59181_-n_0000000000) starting
[junit4] 2> 392211 T2997 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 392214 T3021 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 392214 T2997 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 392215 T2997 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 392217 T2997 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 392218 T3020 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 392219 T3022 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 392219 T3022 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 392220 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 392221 T3022 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 392222 T3020 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 392222 T3020 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:59181",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59181_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 392222 T3020 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 392222 T3020 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 392224 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 392225 T3019 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 393221 T3022 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 393221 T3022 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1389814081474/collection1
[junit4] 2> 393222 T3022 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 393222 T3022 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 393222 T3022 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 393223 T3022 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1389814081474/collection1/'
[junit4] 2> 393224 T3022 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1389814081474/collection1/lib/classes/' to classloader
[junit4] 2> 393224 T3022 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1389814081474/collection1/lib/README' to classloader
[junit4] 2> 393250 T3022 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 393259 T3022 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 393260 T3022 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 393264 T3022 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 393365 T3022 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 393366 T3022 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 393367 T3022 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 393369 T3022 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 393382 T3022 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 393383 T3022 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1389814081474/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/control/data/
[junit4] 2> 393383 T3022 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2007d2d9
[junit4] 2> 393383 T3022 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/control/data
[junit4] 2> 393383 T3022 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/control/data/index/
[junit4] 2> 393384 T3022 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 393384 T3022 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/control/data/index
[junit4] 2> 393384 T3022 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 393388 T3022 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 393388 T3022 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 393393 T3022 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 393394 T3022 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 393394 T3022 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 393394 T3022 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 393394 T3022 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 393394 T3022 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 393395 T3022 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 393395 T3022 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 393395 T3022 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 393395 T3022 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 393395 T3022 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 393396 T3022 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 393396 T3022 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 393396 T3022 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 393396 T3022 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 393396 T3022 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 393397 T3022 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 393398 T3022 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 393405 T3022 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 393406 T3022 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 393406 T3022 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=23, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7556490005039886]
[junit4] 2> 393407 T3022 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 393407 T3022 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 393407 T3022 oass.SolrIndexSearcher.<init> Opening Searcher@6c3dab37 main
[junit4] 2> 393408 T3023 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6c3dab37 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 393409 T3022 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 393410 T2997 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 393410 T2997 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 393410 T3026 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:59181 collection:control_collection shard:shard1
[junit4] 2> 393411 T2997 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 393412 T3026 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 393412 T3028 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29be8e68 name:ZooKeeperConnection Watcher:127.0.0.1:35649/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 393412 T2997 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 393414 T2997 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 393415 T2997 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 393419 T3026 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 393421 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 393422 T3026 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 393422 T3026 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 393422 T3020 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C1681 name=collection1 org.apache.solr.core.SolrCore@9747fb8 url=http://127.0.0.1:59181/collection1 node=127.0.0.1:59181_ C1681_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:59181, core=collection1, node_name=127.0.0.1:59181_}
[junit4] 2> 393422 T3026 C1681 P59181 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:59181/collection1/
[junit4] 2> 393423 T3026 C1681 P59181 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 393423 T3026 C1681 P59181 oasc.SyncStrategy.syncToMe http://127.0.0.1:59181/collection1/ has no replicas
[junit4] 2> 393423 T3026 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:59181/collection1/ shard1
[junit4] 2> 393423 T3026 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 393425 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 393429 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 393431 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 393480 T2997 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 393481 T2997 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39334
[junit4] 2> 393481 T2997 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 393482 T2997 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 393482 T2997 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1389814082811
[junit4] 2> 393482 T2997 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1389814082811/'
[junit4] 2> 393491 T2997 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1389814082811/solr.xml
[junit4] 2> 393498 T2997 oasc.CoreContainer.<init> New CoreContainer 1938247974
[junit4] 2> 393498 T2997 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1389814082811/]
[junit4] 2> 393498 T2997 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 393499 T2997 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 393499 T2997 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 393499 T2997 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 393499 T2997 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 393500 T2997 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 393500 T2997 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 393500 T2997 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 393500 T2997 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 393502 T2997 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 393505 T2997 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 393505 T2997 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 393506 T2997 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:35649/solr
[junit4] 2> 393506 T2997 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 393507 T2997 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 393509 T3039 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ac70704 name:ZooKeeperConnection Watcher:127.0.0.1:35649 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 393509 T2997 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 393511 T2997 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 393511 T3041 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cdf351f name:ZooKeeperConnection Watcher:127.0.0.1:35649/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 393512 T2997 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 393514 T2997 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 393534 T3019 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 393534 T3041 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 393534 T3028 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 393580 T3026 oasc.ZkController.register We are http://127.0.0.1:59181/collection1/ and leader is http://127.0.0.1:59181/collection1/
[junit4] 2> 393580 T3026 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:59181
[junit4] 2> 393580 T3026 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 393580 T3026 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 393581 T3026 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 393582 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 393582 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 393583 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 393583 T3026 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 393585 T3020 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 393585 T3020 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:59181",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59181_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 393588 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 393692 T3041 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 393692 T3028 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 393692 T3019 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 394516 T2997 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39334_
[junit4] 2> 394518 T2997 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39334_
[junit4] 2> 394519 T3028 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 394519 T3041 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 394519 T3019 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 394523 T3042 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 394524 T3042 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 394525 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 394525 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 394525 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 394525 T3042 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 394527 T3020 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 394528 T3020 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:39334",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:39334_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 394528 T3020 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 394529 T3020 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 394530 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 394633 T3019 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 394633 T3028 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 394633 T3041 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 395526 T3042 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 395526 T3042 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1389814082811/collection1
[junit4] 2> 395527 T3042 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 395527 T3042 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 395527 T3042 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 395528 T3042 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1389814082811/collection1/'
[junit4] 2> 395528 T3042 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1389814082811/collection1/lib/classes/' to classloader
[junit4] 2> 395529 T3042 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1389814082811/collection1/lib/README' to classloader
[junit4] 2> 395543 T3042 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 395558 T3042 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 395559 T3042 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 395563 T3042 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 395678 T3042 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 395680 T3042 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 395680 T3042 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 395682 T3042 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 395695 T3042 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 395695 T3042 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1389814082811/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty1/
[junit4] 2> 395696 T3042 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2007d2d9
[junit4] 2> 395696 T3042 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty1
[junit4] 2> 395697 T3042 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty1/index/
[junit4] 2> 395697 T3042 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 395697 T3042 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty1/index
[junit4] 2> 395698 T3042 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 395700 T3042 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 395700 T3042 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 395702 T3042 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 395702 T3042 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 395703 T3042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 395703 T3042 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 395703 T3042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 395703 T3042 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 395703 T3042 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 395703 T3042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 395704 T3042 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 395704 T3042 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 395704 T3042 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 395704 T3042 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 395704 T3042 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 395705 T3042 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 395705 T3042 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 395705 T3042 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 395706 T3042 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 395707 T3042 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 395708 T3042 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 395708 T3042 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 395708 T3042 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=23, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7556490005039886]
[junit4] 2> 395709 T3042 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 395709 T3042 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 395710 T3042 oass.SolrIndexSearcher.<init> Opening Searcher@278b97c3 main
[junit4] 2> 395711 T3043 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@278b97c3 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 395713 T3042 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 395713 T2997 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 395714 T2997 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 395713 T3046 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39334 collection:collection1 shard:shard2
[junit4] 2> 395715 T3046 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 395719 T3046 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 395721 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 395721 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 395721 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 395721 T3046 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 395722 T3046 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 395722 T3020 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C1682 name=collection1 org.apache.solr.core.SolrCore@16fe636 url=http://127.0.0.1:39334/collection1 node=127.0.0.1:39334_ C1682_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:39334, core=collection1, node_name=127.0.0.1:39334_}
[junit4] 2> 395722 T3046 C1682 P39334 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39334/collection1/
[junit4] 2> 395723 T3046 C1682 P39334 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 395723 T3046 C1682 P39334 oasc.SyncStrategy.syncToMe http://127.0.0.1:39334/collection1/ has no replicas
[junit4] 2> 395724 T3046 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39334/collection1/ shard2
[junit4] 2> 395724 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 395724 T3046 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 395731 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 395795 T2997 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 395797 T2997 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:34411
[junit4] 2> 395797 T2997 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 395798 T2997 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 395798 T2997 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1389814085110
[junit4] 2> 395798 T2997 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1389814085110/'
[junit4] 2> 395808 T2997 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1389814085110/solr.xml
[junit4] 2> 395827 T2997 oasc.CoreContainer.<init> New CoreContainer 1509424794
[junit4] 2> 395827 T2997 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1389814085110/]
[junit4] 2> 395828 T2997 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 395828 T2997 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 395828 T2997 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 395828 T2997 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 395829 T2997 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 395829 T2997 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 395829 T2997 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 395829 T2997 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 395829 T2997 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 395831 T2997 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 395831 T2997 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 395832 T2997 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 395832 T2997 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:35649/solr
[junit4] 2> 395832 T2997 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 395833 T2997 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 395834 T3019 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 395834 T3028 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 395834 T3041 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 395835 T3057 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f59ca10 name:ZooKeeperConnection Watcher:127.0.0.1:35649 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 395835 T2997 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 395837 T2997 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 395838 T3059 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d774d98 name:ZooKeeperConnection Watcher:127.0.0.1:35649/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 395838 T2997 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 395841 T2997 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 395879 T3046 oasc.ZkController.register We are http://127.0.0.1:39334/collection1/ and leader is http://127.0.0.1:39334/collection1/
[junit4] 2> 395879 T3046 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39334
[junit4] 2> 395879 T3046 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 395879 T3046 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 395880 T3046 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 395881 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 395881 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 395881 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 395881 T3046 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 395882 T3020 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 395883 T3020 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:39334",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:39334_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 395885 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 395987 T3041 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 395987 T3059 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 395987 T3028 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 395987 T3019 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 396843 T2997 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34411_
[junit4] 2> 396844 T2997 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34411_
[junit4] 2> 396846 T3028 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 396846 T3041 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 396846 T3059 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 396846 T3019 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 396849 T3060 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 396849 T3060 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 396850 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 396850 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 396850 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 396850 T3060 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 396851 T3020 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 396852 T3020 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:34411",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:34411_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 396852 T3020 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 396852 T3020 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 396853 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 396956 T3059 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 396956 T3028 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 396956 T3019 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 396956 T3041 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 397851 T3060 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 397851 T3060 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1389814085110/collection1
[junit4] 2> 397852 T3060 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 397853 T3060 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 397853 T3060 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 397854 T3060 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1389814085110/collection1/'
[junit4] 2> 397855 T3060 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1389814085110/collection1/lib/classes/' to classloader
[junit4] 2> 397856 T3060 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1389814085110/collection1/lib/README' to classloader
[junit4] 2> 397876 T3060 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 397884 T3060 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 397885 T3060 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 397890 T3060 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 398022 T3060 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 398023 T3060 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 398024 T3060 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 398026 T3060 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 398039 T3060 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 398040 T3060 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1389814085110/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty2/
[junit4] 2> 398040 T3060 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2007d2d9
[junit4] 2> 398040 T3060 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty2
[junit4] 2> 398040 T3060 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty2/index/
[junit4] 2> 398041 T3060 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 398041 T3060 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty2/index
[junit4] 2> 398041 T3060 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 398043 T3060 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 398043 T3060 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 398045 T3060 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 398046 T3060 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 398046 T3060 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 398046 T3060 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 398046 T3060 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 398046 T3060 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 398047 T3060 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 398047 T3060 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 398047 T3060 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 398047 T3060 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 398047 T3060 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 398047 T3060 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 398048 T3060 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 398048 T3060 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 398048 T3060 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 398048 T3060 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 398049 T3060 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 398050 T3060 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 398051 T3060 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 398052 T3060 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 398052 T3060 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=23, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7556490005039886]
[junit4] 2> 398053 T3060 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 398053 T3060 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 398054 T3060 oass.SolrIndexSearcher.<init> Opening Searcher@6562939d main
[junit4] 2> 398056 T3061 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6562939d main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 398057 T3060 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 398058 T2997 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 398058 T2997 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 398058 T3064 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:34411 collection:collection1 shard:shard3
[junit4] 2> 398059 T3064 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 398066 T3064 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
[junit4] 2> 398067 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 398067 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 398068 T3064 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 398068 T3064 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 398068 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> ASYNC NEW_CORE C1683 name=collection1 org.apache.solr.core.SolrCore@6d60b9c3 url=http://127.0.0.1:34411/collection1 node=127.0.0.1:34411_ C1683_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:34411, core=collection1, node_name=127.0.0.1:34411_}
[junit4] 2> 398068 T3064 C1683 P34411 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:34411/collection1/
[junit4] 2> 398068 T3064 C1683 P34411 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 398068 T3020 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 398068 T3064 C1683 P34411 oasc.SyncStrategy.syncToMe http://127.0.0.1:34411/collection1/ has no replicas
[junit4] 2> 398069 T3064 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:34411/collection1/ shard3
[junit4] 2> 398069 T3064 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 398070 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 398073 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 398076 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 398124 T2997 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 398126 T2997 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50363
[junit4] 2> 398126 T2997 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 398126 T2997 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 398127 T2997 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1389814087455
[junit4] 2> 398127 T2997 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1389814087455/'
[junit4] 2> 398136 T2997 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1389814087455/solr.xml
[junit4] 2> 398143 T2997 oasc.CoreContainer.<init> New CoreContainer 1014250185
[junit4] 2> 398143 T2997 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1389814087455/]
[junit4] 2> 398144 T2997 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 398144 T2997 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 398144 T2997 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 398144 T2997 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 398145 T2997 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 398145 T2997 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 398145 T2997 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 398145 T2997 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 398145 T2997 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 398148 T2997 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 398148 T2997 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 398148 T2997 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 398149 T2997 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:35649/solr
[junit4] 2> 398149 T2997 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 398150 T2997 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 398153 T3075 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e9aa7f7 name:ZooKeeperConnection Watcher:127.0.0.1:35649 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 398153 T2997 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 398155 T2997 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 398156 T3077 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c14f33c name:ZooKeeperConnection Watcher:127.0.0.1:35649/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 398156 T2997 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 398158 T2997 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 398179 T3041 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 398179 T3059 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 398179 T3019 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 398179 T3077 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 398179 T3028 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 398224 T3064 oasc.ZkController.register We are http://127.0.0.1:34411/collection1/ and leader is http://127.0.0.1:34411/collection1/
[junit4] 2> 398224 T3064 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34411
[junit4] 2> 398224 T3064 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 398225 T3064 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 398225 T3064 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 398226 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 398226 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 398226 T3064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 398226 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 398227 T3020 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 398228 T3020 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:34411",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:34411_",
[junit4] 2> "shard":"shard3",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 398229 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 398332 T3041 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 398332 T3077 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 398332 T3019 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 398332 T3028 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 398332 T3059 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 399160 T2997 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50363_
[junit4] 2> 399162 T2997 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50363_
[junit4] 2> 399164 T3041 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 399164 T3077 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 399164 T3059 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 399164 T3028 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 399164 T3019 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 399183 T3078 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 399183 T3078 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 399184 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 399184 T3078 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 399184 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 399185 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 399186 T3020 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 399186 T3020 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:50363",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50363_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 399187 T3020 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 399187 T3020 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 399190 T3019 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 399292 T3077 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 399292 T3041 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 399292 T3059 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 399292 T3028 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 399292 T3019 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 400184 T3078 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 400185 T3078 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1389814087455/collection1
[junit4] 2> 400185 T3078 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 400186 T3078 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 400186 T3078 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 400187 T3078 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1389814087455/collection1/'
[junit4] 2> 400187 T3078 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1389814087455/collection1/lib/classes/' to classloader
[junit4] 2> 400187 T3078 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1389814087455/collection1/lib/README' to classloader
[junit4] 2> 400201 T3078 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 400209 T3078 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 400210 T3078 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 400214 T3078 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 400321 T3078 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 400322 T3078 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 400323 T3078 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 400325 T3078 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 400345 T3078 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 400345 T3078 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1389814087455/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty3/
[junit4] 2> 400346 T3078 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2007d2d9
[junit4] 2> 400346 T3078 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty3
[junit4] 2> 400346 T3078 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty3/index/
[junit4] 2> 400346 T3078 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 400347 T3078 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty3/index
[junit4] 2> 400347 T3078 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 400349 T3078 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1389814081183/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 400350 T3078 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 400352 T3078 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 400352 T3078 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 400352 T3078 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 400352 T3078 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 400352 T3078 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 400353 T3078 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 400353 T3078 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 400353 T3078 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 400353 T3078 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 400353 T3078 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 400354 T3078 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 400354 T3078 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: sol
[...truncated too long message...]
Manager$1.run(SelectorManager.java:290)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 86) Thread[id=4091, name=coreZkRegister-2360-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 87) Thread[id=3544, name=qtp1566641015-3544 Acceptor1 SelectChannelConnector@127.0.0.1:58070, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:956)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 88) Thread[id=4072, name=qtp377434478-4072 Selector0, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.nio.ch.EPollArrayWrapper.interrupt(Native Method)
[junit4] 2> at sun.nio.ch.EPollArrayWrapper.interrupt(EPollArrayWrapper.java:317)
[junit4] 2> at sun.nio.ch.EPollSelectorImpl.wakeup(EPollSelectorImpl.java:193)
[junit4] 2> at java.nio.channels.spi.AbstractSelector$1.interrupt(AbstractSelector.java:213)
[junit4] 2> at java.nio.channels.spi.AbstractSelector.begin(AbstractSelector.java:219)
[junit4] 2> at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:78)
[junit4] 2> at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
[junit4] 2> at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 89) Thread[id=4142, name=qtp1736040527-4142 Acceptor0 SelectChannelConnector@127.0.0.1:40096, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:956)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=ko_KR, timezone=America/Ensenada
[junit4] 2> NOTE: Linux 3.8.0-35-generic amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=8,threads=110,free=60865832,total=242335744
[junit4] 2> NOTE: All tests run in this JVM: [TestTrie, AssignTest, BJQParserTest, MoreLikeThisHandlerTest, TestWriterPerf, TestQueryUtils, TestSchemaResource, PolyFieldTest, SolrCoreTest, TestPHPSerializedResponseWriter, TestFieldTypeCollectionResource, TestInfoStreamLogging, BasicFunctionalityTest, LoggingHandlerTest, SoftAutoCommitTest, SuggesterTest, DeleteShardTest, StressHdfsTest, BadComponentTest, TestSuggestSpellingConverter, TermVectorComponentTest, TestStressVersions, DOMUtilTest, TestElisionMultitermQuery, TestGroupingSearch, TestReversedWildcardFilterFactory, SOLR749Test, SuggesterFSTTest, QueryEqualityTest, QueryResultKeyTest, TestLMDirichletSimilarityFactory, HdfsDirectoryTest, MBeansHandlerTest, FastVectorHighlighterTest, DocValuesTest, HdfsBasicDistributedZkTest, BasicDistributedZkTest, TestSolrQueryParser, TestLFUCache, TestShardHandlerFactory, StatelessScriptUpdateProcessorFactoryTest, TestNRTOpen, SolrTestCaseJ4Test, TestJoin, DateMathParserTest, RecoveryZkTest, TestMergePolicyConfig, PrimitiveFieldTypeTest, TestClassNameShortening, ShardRoutingTest, SolrInfoMBeanTest, TestSort, TestImplicitCoreProperties, TestSystemIdResolver, HdfsSyncSliceTest, TestLMJelinekMercerSimilarityFactory, CursorMarkTest, SliceStateUpdateTest, DistributedSpellCheckComponentTest, DirectUpdateHandlerOptimizeTest, QueryElevationComponentTest, TestManagedSchemaFieldResource, LegacyHTMLStripCharFilterTest, DocumentBuilderTest, TestReplicationHandler, OverseerTest, TestPostingsSolrHighlighter, TestPerFieldSimilarity, TestExtendedDismaxParser, UpdateParamsTest, RangeFacetTest, PeerSyncTest, CoreAdminCreateDiscoverTest, SampleTest, TestCoreContainer, AutoCommitTest, HdfsCollectionsAPIDistributedZkTest, ReturnFieldsTest, WordBreakSolrSpellCheckerTest, TestRemoteStreaming, TestDefaultSearchFieldResource, TestLRUCache, UpdateRequestProcessorFactoryTest, SliceStateTest, EchoParamsTest, DistributedQueryComponentCustomSortTest, SpatialFilterTest, AnalysisAfterCoreReloadTest, ChaosMonkeySafeLeaderTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=D4BF55D80BE0B97D -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ko_KR -Dtests.timezone=America/Ensenada -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J0 | ChaosMonkeySafeLeaderTest (suite) <<<
[junit4] > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4] > at __randomizedtesting.SeedInfo.seed([D4BF55D80BE0B97D]:0)Throwable #2: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=3397, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] > Caused by: java.lang.AssertionError: liveDocs.count()=15 info.docCount=30 info.getDelCount()=19
[junit4] > at __randomizedtesting.SeedInfo.seed([D4BF55D80BE0B97D]:0)
[junit4] > at org.apache.lucene.codecs.lucene40.Lucene40LiveDocsFormat.readLiveDocs(Lucene40LiveDocsFormat.java:92)
[junit4] > at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:103)
[junit4] > at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:131)
[junit4] > at org.apache.lucene.index.ReadersAndUpdates.getReadOnlyClone(ReadersAndUpdates.java:183)
[junit4] > at org.apache.lucene.index.StandardDirectoryReader.open(StandardDirectoryReader.java:97)
[junit4] > at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:380)
[junit4] > at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:268)
[junit4] > at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:204)
[junit4] > at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1444)
[junit4] > at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1632)
[junit4] > at org.apache.solr.handler.SnapPuller.openNewSearcherAndUpdateCommitPoint(SnapPuller.java:670)
[junit4] > at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:490)
[junit4] > at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:322)
[junit4] > at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:155)
[junit4] > at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:437)
[junit4] > at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:247)
[junit4] Completed on J0 in 7226.11s, 1 test, 3 errors <<< FAILURES!
[...truncated 11 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:453: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:433: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1304: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:937: There were test failures: 362 suites, 1594 tests, 2 suite-level errors, 1 error, 34 ignored (6 assumptions)
Total time: 149 minutes 50 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0-ea-b123 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure