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/02/28 04:31:47 UTC
[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0-fcs-b129) - Build
# 9618 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9618/
Java: 64bit/jdk1.8.0-fcs-b129 -XX:+UseCompressedOops -XX:+UseSerialGC
2 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([E729C2CF22B5545B]:0)
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([E729C2CF22B5545B]:0)
Build Log:
[...truncated 11402 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4] 2> 373053 T2737 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
[junit4] 2> 373053 T2737 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /kq_m/nc
[junit4] 2> 373056 T2737 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-1393551053160
[junit4] 2> 373056 T2737 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 373057 T2738 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 373157 T2737 oasc.ZkTestServer.run start zk server on port:49393
[junit4] 2> 373157 T2737 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 373240 T2744 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75c9eba6 name:ZooKeeperConnection Watcher:127.0.0.1:49393 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 373240 T2737 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 373241 T2737 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 373246 T2737 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 373247 T2746 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@38457c08 name:ZooKeeperConnection Watcher:127.0.0.1:49393/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 373247 T2737 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 373247 T2737 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 373249 T2737 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 373250 T2737 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 373251 T2737 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 373252 T2737 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 373252 T2737 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 373255 T2737 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 373255 T2737 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 373257 T2737 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 373257 T2737 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 373259 T2737 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 373259 T2737 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 373261 T2737 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 373261 T2737 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 373262 T2737 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 373263 T2737 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 373264 T2737 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 373264 T2737 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 373266 T2737 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 373267 T2737 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 373269 T2737 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 373269 T2737 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 373271 T2737 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 373271 T2737 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 373273 T2737 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 373273 T2737 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 373275 T2737 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 373276 T2748 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a179717 name:ZooKeeperConnection Watcher:127.0.0.1:49393/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 373277 T2737 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 373480 T2737 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 373482 T2737 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 373487 T2737 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:49188
[junit4] 2> 373488 T2737 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 373488 T2737 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 373488 T2737 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393551053382
[junit4] 2> 373488 T2737 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393551053382/'
[junit4] 2> 373497 T2737 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-1393551053382/solr.xml
[junit4] 2> 373509 T2737 oasc.CoreContainer.<init> New CoreContainer 1288694437
[junit4] 2> 373509 T2737 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393551053382/]
[junit4] 2> 373510 T2737 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 373510 T2737 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 373510 T2737 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 373510 T2737 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 373511 T2737 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 373511 T2737 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 373511 T2737 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 373511 T2737 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 373511 T2737 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 373514 T2737 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 373514 T2737 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 373515 T2737 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 373515 T2737 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49393/solr
[junit4] 2> 373515 T2737 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 373516 T2737 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 373517 T2759 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@622aa98b name:ZooKeeperConnection Watcher:127.0.0.1:49393 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 373518 T2737 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 373519 T2737 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 373520 T2761 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2397a0dd name:ZooKeeperConnection Watcher:127.0.0.1:49393/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 373520 T2737 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 373521 T2737 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 373523 T2737 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 373525 T2737 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 373526 T2737 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49188_kq_m%2Fnc
[junit4] 2> 373527 T2737 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49188_kq_m%2Fnc
[junit4] 2> 373528 T2737 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 373529 T2737 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 373531 T2737 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49188_kq_m%2Fnc
[junit4] 2> 373531 T2737 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 373532 T2737 oasc.Overseer.start Overseer (id=91327761820090372-127.0.0.1:49188_kq_m%2Fnc-n_0000000000) starting
[junit4] 2> 373534 T2737 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 373539 T2763 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 373539 T2737 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 373540 T2763 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 373545 T2737 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 373546 T2737 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 373549 T2762 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 373549 T2764 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 373550 T2764 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 373550 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 373551 T2764 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 373551 T2762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 373552 T2762 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:49188/kq_m/nc",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49188_kq_m%2Fnc",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 373552 T2762 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 373552 T2762 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 373553 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 373554 T2761 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> 374551 T2764 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 374551 T2764 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393551053382/collection1
[junit4] 2> 374551 T2764 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 374552 T2764 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 374552 T2764 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 374553 T2764 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 374553 T2764 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393551053382/collection1/'
[junit4] 2> 374553 T2764 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-1393551053382/collection1/lib/.svn/' to classloader
[junit4] 2> 374553 T2764 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-1393551053382/collection1/lib/classes/' to classloader
[junit4] 2> 374554 T2764 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-1393551053382/collection1/lib/README' to classloader
[junit4] 2> 374568 T2764 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 374575 T2764 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 374576 T2764 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 374579 T2764 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 374674 T2764 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 374675 T2764 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 374675 T2764 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 374678 T2764 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 374691 T2764 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 374692 T2764 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393551053382/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393551053160/control/data/
[junit4] 2> 374692 T2764 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7ead9935
[junit4] 2> 374693 T2764 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-1393551053160/control/data
[junit4] 2> 374693 T2764 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393551053160/control/data/index/
[junit4] 2> 374693 T2764 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393551053160/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 374694 T2764 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-1393551053160/control/data/index
[junit4] 2> 374694 T2764 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=49, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 374697 T2764 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-1393551053160/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 374697 T2764 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 374699 T2764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 374700 T2764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 374700 T2764 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 374700 T2764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 374700 T2764 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 374701 T2764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 374701 T2764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 374701 T2764 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 374701 T2764 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 374702 T2764 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 374702 T2764 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 374702 T2764 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 374703 T2764 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 374703 T2764 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 374703 T2764 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 374704 T2764 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 374704 T2764 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 374706 T2764 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 374707 T2764 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 374707 T2764 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 374708 T2764 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=22, maxMergeAtOnceExplicit=48, maxMergedSegmentMB=14.5380859375, floorSegmentMB=0.884765625, forceMergeDeletesPctAllowed=20.13039314990548, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 374709 T2764 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-1393551053160/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 374709 T2764 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 374709 T2764 oass.SolrIndexSearcher.<init> Opening Searcher@528b9cf9[collection1] main
[junit4] 2> 374711 T2765 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@528b9cf9[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 374712 T2764 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 374713 T2737 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 374713 T2737 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 374713 T2768 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:49188/kq_m/nc collection:control_collection shard:shard1
[junit4] 2> 374715 T2768 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 374716 T2737 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 374717 T2770 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50110101 name:ZooKeeperConnection Watcher:127.0.0.1:49393/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 374717 T2737 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 374718 T2737 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 374720 T2768 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 374720 T2737 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 374721 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 374721 T2768 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 374721 T2768 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1303 name=collection1 org.apache.solr.core.SolrCore@3047151d url=https://127.0.0.1:49188/kq_m/nc/collection1 node=127.0.0.1:49188_kq_m%2Fnc C1303_STATE=coll:control_collection core:collection1 props:{state=down, base_url=https://127.0.0.1:49188/kq_m/nc, core=collection1, node_name=127.0.0.1:49188_kq_m%2Fnc}
[junit4] 2> 374722 T2768 C1303 P49188 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:49188/kq_m/nc/collection1/
[junit4] 2> 374722 T2762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 374722 T2768 C1303 P49188 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 374722 T2768 C1303 P49188 oasc.SyncStrategy.syncToMe https://127.0.0.1:49188/kq_m/nc/collection1/ has no replicas
[junit4] 2> 374722 T2768 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:49188/kq_m/nc/collection1/ shard1
[junit4] 2> 374723 T2768 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 374724 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 374728 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 374731 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 374834 T2761 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> 374834 T2770 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> 374879 T2768 oasc.ZkController.register We are https://127.0.0.1:49188/kq_m/nc/collection1/ and leader is https://127.0.0.1:49188/kq_m/nc/collection1/
[junit4] 2> 374879 T2768 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:49188/kq_m/nc
[junit4] 2> 374879 T2768 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 374879 T2768 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 374879 T2768 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 374880 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 374880 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 374880 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 374881 T2768 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 374882 T2762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 374882 T2762 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"https://127.0.0.1:49188/kq_m/nc",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49188_kq_m%2Fnc",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 374884 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 374967 T2737 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 374967 T2737 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 374970 T2737 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 374971 T2737 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:37144
[junit4] 2> 374972 T2737 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 374972 T2737 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 374973 T2737 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-1393551054825
[junit4] 2> 374973 T2737 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-1393551054825/'
[junit4] 2> 374982 T2737 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-1393551054825/solr.xml
[junit4] 2> 374986 T2761 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> 374986 T2770 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> 374997 T2737 oasc.CoreContainer.<init> New CoreContainer 1269536802
[junit4] 2> 374997 T2737 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-1393551054825/]
[junit4] 2> 374998 T2737 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 374998 T2737 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 374998 T2737 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 374998 T2737 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 374998 T2737 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 374999 T2737 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 374999 T2737 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 374999 T2737 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 374999 T2737 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 375002 T2737 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 375002 T2737 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 375002 T2737 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 375003 T2737 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49393/solr
[junit4] 2> 375003 T2737 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 375004 T2737 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 375005 T2781 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2bfccfd8 name:ZooKeeperConnection Watcher:127.0.0.1:49393 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 375005 T2737 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 375007 T2737 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 375009 T2783 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e64e15a name:ZooKeeperConnection Watcher:127.0.0.1:49393/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 375010 T2737 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 375012 T2737 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 376015 T2737 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37144_kq_m%2Fnc
[junit4] 2> 376016 T2737 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37144_kq_m%2Fnc
[junit4] 2> 376018 T2761 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 376018 T2770 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 376019 T2783 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 376022 T2784 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 376022 T2784 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 376023 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 376023 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 376023 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 376023 T2784 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 376024 T2762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 376025 T2762 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:37144/kq_m/nc",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37144_kq_m%2Fnc",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 376025 T2762 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 376025 T2762 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 376026 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 376132 T2770 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> 376132 T2761 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> 376132 T2783 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> 377024 T2784 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 377024 T2784 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-1393551054825/collection1
[junit4] 2> 377024 T2784 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 377025 T2784 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 377025 T2784 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 377025 T2784 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 377026 T2784 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-1393551054825/collection1/'
[junit4] 2> 377026 T2784 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-1393551054825/collection1/lib/.svn/' to classloader
[junit4] 2> 377026 T2784 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-1393551054825/collection1/lib/classes/' to classloader
[junit4] 2> 377026 T2784 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-1393551054825/collection1/lib/README' to classloader
[junit4] 2> 377041 T2784 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 377049 T2784 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 377050 T2784 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 377054 T2784 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 377157 T2784 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 377159 T2784 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 377160 T2784 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 377163 T2784 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 377176 T2784 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 377177 T2784 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-1393551054825/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393551053160/jetty1/
[junit4] 2> 377177 T2784 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7ead9935
[junit4] 2> 377177 T2784 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-1393551053160/jetty1
[junit4] 2> 377178 T2784 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393551053160/jetty1/index/
[junit4] 2> 377178 T2784 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393551053160/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 377178 T2784 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-1393551053160/jetty1/index
[junit4] 2> 377178 T2784 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=49, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 377181 T2784 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-1393551053160/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 377181 T2784 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 377183 T2784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 377183 T2784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 377183 T2784 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 377183 T2784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 377183 T2784 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 377184 T2784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 377184 T2784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 377184 T2784 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 377184 T2784 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 377185 T2784 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 377185 T2784 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 377185 T2784 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 377185 T2784 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 377185 T2784 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 377186 T2784 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 377186 T2784 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 377186 T2784 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 377188 T2784 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 377189 T2784 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 377189 T2784 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 377190 T2784 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=22, maxMergeAtOnceExplicit=48, maxMergedSegmentMB=14.5380859375, floorSegmentMB=0.884765625, forceMergeDeletesPctAllowed=20.13039314990548, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 377191 T2784 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-1393551053160/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 377191 T2784 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 377191 T2784 oass.SolrIndexSearcher.<init> Opening Searcher@416eb02e[collection1] main
[junit4] 2> 377193 T2785 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@416eb02e[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 377195 T2784 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 377195 T2737 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 377196 T2737 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 377195 T2788 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:37144/kq_m/nc collection:collection1 shard:shard2
[junit4] 2> 377197 T2788 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 377202 T2788 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 377204 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 377204 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 377204 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 377205 T2788 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 377205 T2788 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 377205 T2762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C1304 name=collection1 org.apache.solr.core.SolrCore@108ad83d url=https://127.0.0.1:37144/kq_m/nc/collection1 node=127.0.0.1:37144_kq_m%2Fnc C1304_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:37144/kq_m/nc, core=collection1, node_name=127.0.0.1:37144_kq_m%2Fnc}
[junit4] 2> 377205 T2788 C1304 P37144 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:37144/kq_m/nc/collection1/
[junit4] 2> 377206 T2788 C1304 P37144 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 377206 T2788 C1304 P37144 oasc.SyncStrategy.syncToMe https://127.0.0.1:37144/kq_m/nc/collection1/ has no replicas
[junit4] 2> 377206 T2788 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:37144/kq_m/nc/collection1/ shard2
[junit4] 2> 377207 T2788 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 377209 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 377211 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 377214 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 377319 T2770 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> 377319 T2783 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> 377319 T2761 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> 377362 T2788 oasc.ZkController.register We are https://127.0.0.1:37144/kq_m/nc/collection1/ and leader is https://127.0.0.1:37144/kq_m/nc/collection1/
[junit4] 2> 377363 T2788 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:37144/kq_m/nc
[junit4] 2> 377363 T2788 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 377363 T2788 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 377363 T2788 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 377364 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 377364 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 377364 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 377365 T2788 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 377365 T2762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 377366 T2762 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"https://127.0.0.1:37144/kq_m/nc",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37144_kq_m%2Fnc",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 377367 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 377408 T2737 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 377409 T2737 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 377412 T2737 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 377413 T2737 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:50022
[junit4] 2> 377415 T2737 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 377415 T2737 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 377416 T2737 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393551057301
[junit4] 2> 377416 T2737 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393551057301/'
[junit4] 2> 377425 T2737 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-jetty2-1393551057301/solr.xml
[junit4] 2> 377432 T2737 oasc.CoreContainer.<init> New CoreContainer 1001530769
[junit4] 2> 377432 T2737 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393551057301/]
[junit4] 2> 377433 T2737 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 377433 T2737 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 377433 T2737 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 377433 T2737 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 377434 T2737 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 377434 T2737 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 377434 T2737 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 377434 T2737 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 377435 T2737 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 377437 T2737 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 377438 T2737 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 377438 T2737 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 377438 T2737 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49393/solr
[junit4] 2> 377438 T2737 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 377439 T2737 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 377440 T2799 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a0d2a56 name:ZooKeeperConnection Watcher:127.0.0.1:49393 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 377440 T2737 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 377442 T2737 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 377443 T2801 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e7d37aa name:ZooKeeperConnection Watcher:127.0.0.1:49393/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 377443 T2737 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 377446 T2737 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 377469 T2761 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> 377469 T2770 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> 377469 T2783 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> 377469 T2801 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> 378448 T2737 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50022_kq_m%2Fnc
[junit4] 2> 378449 T2737 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50022_kq_m%2Fnc
[junit4] 2> 378463 T2761 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 378463 T2783 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 378463 T2770 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 378463 T2801 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 378467 T2802 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 378467 T2802 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 378468 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 378468 T2802 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 378468 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 378468 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 378469 T2762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 378470 T2762 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:50022/kq_m/nc",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50022_kq_m%2Fnc",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 378470 T2762 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 378470 T2762 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 378472 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 378576 T2761 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> 378576 T2770 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> 378576 T2801 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> 378576 T2783 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> 379468 T2802 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 379469 T2802 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393551057301/collection1
[junit4] 2> 379469 T2802 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 379469 T2802 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 379469 T2802 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 379470 T2802 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 379470 T2802 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393551057301/collection1/'
[junit4] 2> 379471 T2802 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-1393551057301/collection1/lib/.svn/' to classloader
[junit4] 2> 379471 T2802 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-1393551057301/collection1/lib/classes/' to classloader
[junit4] 2> 379471 T2802 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-1393551057301/collection1/lib/README' to classloader
[junit4] 2> 379487 T2802 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 379496 T2802 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 379497 T2802 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 379501 T2802 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 379602 T2802 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 379603 T2802 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 379603 T2802 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 379605 T2802 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 379618 T2802 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 379618 T2802 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393551057301/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393551053160/jetty2/
[junit4] 2> 379618 T2802 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7ead9935
[junit4] 2> 379618 T2802 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-1393551053160/jetty2
[junit4] 2> 379619 T2802 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393551053160/jetty2/index/
[junit4] 2> 379619 T2802 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393551053160/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 379619 T2802 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-1393551053160/jetty2/index
[junit4] 2> 379619 T2802 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=49, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 379622 T2802 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-1393551053160/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 379622 T2802 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 379623 T2802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 379624 T2802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 379624 T2802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 379624 T2802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 379624 T2802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 379624 T2802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 379625 T2802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 379625 T2802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 379625 T2802 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 379625 T2802 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 379625 T2802 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 379626 T2802 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 379626 T2802 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 379626 T2802 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 379626 T2802 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 379626 T2802 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 379627 T2802 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 379628 T2802 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 379629 T2802 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 379629 T2802 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 379630 T2802 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=22, maxMergeAtOnceExplicit=48, maxMergedSegmentMB=14.5380859375, floorSegmentMB=0.884765625, forceMergeDeletesPctAllowed=20.13039314990548, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 379631 T2802 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-1393551053160/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 379631 T2802 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 379631 T2802 oass.SolrIndexSearcher.<init> Opening Searcher@2ac8449[collection1] main
[junit4] 2> 379633 T2803 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2ac8449[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 379635 T2802 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 379636 T2737 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 379636 T2737 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 379639 T2806 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:50022/kq_m/nc collection:collection1 shard:shard3
[junit4] 2> 379641 T2806 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 379648 T2806 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
[junit4] 2> 379649 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 379650 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 379650 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 379651 T2806 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 379651 T2762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 379651 T2806 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1305 name=collection1 org.apache.solr.core.SolrCore@1077d9e url=https://127.0.0.1:50022/kq_m/nc/collection1 node=127.0.0.1:50022_kq_m%2Fnc C1305_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:50022/kq_m/nc, core=collection1, node_name=127.0.0.1:50022_kq_m%2Fnc}
[junit4] 2> 379651 T2806 C1305 P50022 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:50022/kq_m/nc/collection1/
[junit4] 2> 379652 T2806 C1305 P50022 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 379653 T2806 C1305 P50022 oasc.SyncStrategy.syncToMe https://127.0.0.1:50022/kq_m/nc/collection1/ has no replicas
[junit4] 2> 379654 T2806 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:50022/kq_m/nc/collection1/ shard3
[junit4] 2> 379654 T2806 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 379656 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 379660 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 379662 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 379767 T2801 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> 379767 T2783 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> 379767 T2770 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> 379767 T2761 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> 379811 T2806 oasc.ZkController.register We are https://127.0.0.1:50022/kq_m/nc/collection1/ and leader is https://127.0.0.1:50022/kq_m/nc/collection1/
[junit4] 2> 379811 T2806 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:50022/kq_m/nc
[junit4] 2> 379811 T2806 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 379812 T2806 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 379812 T2806 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 379813 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 379813 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 379813 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 379813 T2806 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 379814 T2762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 379815 T2762 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"https://127.0.0.1:50022/kq_m/nc",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50022_kq_m%2Fnc",
[junit4] 2> "shard":"shard3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 379817 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 379918 T2761 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> 379918 T2770 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> 379918 T2801 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> 379918 T2783 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> 379948 T2737 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 379949 T2737 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 379951 T2737 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 379952 T2737 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:45795
[junit4] 2> 379953 T2737 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 379953 T2737 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 379954 T2737 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-1393551059741
[junit4] 2> 379954 T2737 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-1393551059741/'
[junit4] 2> 379963 T2737 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-1393551059741/solr.xml
[junit4] 2> 379969 T2737 oasc.CoreContainer.<init> New CoreContainer 680940954
[junit4] 2> 379970 T2737 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-1393551059741/]
[junit4] 2> 379970 T2737 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 379970 T2737 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 379971 T2737 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 379971 T2737 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 379971 T2737 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 379972 T2737 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 379972 T2737 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 379972 T2737 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 379972 T2737 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 379982 T2737 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 379982 T2737 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 379982 T2737 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 379983 T2737 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49393/solr
[junit4] 2> 379983 T2737 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 379984 T2737 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 379985 T2817 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f2fa1cb name:ZooKeeperConnection Watcher:127.0.0.1:49393 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 379985 T2737 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 379986 T2737 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 379987 T2819 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@22f0ec7c name:ZooKeeperConnection Watcher:127.0.0.1:49393/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 379988 T2737 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 379991 T2737 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 380993 T2737 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45795_kq_m%2Fnc
[junit4] 2> 380994 T2737 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45795_kq_m%2Fnc
[junit4] 2> 380996 T2761 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 380996 T2783 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 380996 T2801 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 380996 T2770 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 380996 T2819 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 380999 T2820 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 380999 T2820 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 381002 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 381002 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 381002 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 381002 T2820 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 381003 T2762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 381004 T2762 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:45795/kq_m/nc",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:45795_kq_m%2Fnc",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 381004 T2762 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 381004 T2762 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 381006 T2761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 381108 T2761 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> 381109 T2770 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> 381109 T2819 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> 381109 T2783 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> 381108 T2801 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> 382003 T2820 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 382003 T2820 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-1393551059741/collection1
[junit4] 2> 382003 T2820 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 382004 T2820 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 382004 T2820 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 382006 T2820 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 382006 T2820 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-1393551059741/collection1/'
[junit4] 2> 382007 T2820 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-1393551059741/collection1/lib/.svn/' to classloader
[junit4] 2> 382007 T2820 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-1393551059741/collection1/lib/classes/' to classloader
[junit4] 2> 382007 T2820 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-1393551059741/collection1/lib/README' to classloader
[junit4] 2> 382034 T2820 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 382042 T2820 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 382043 T2820 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 382047 T2820 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 382146 T2820 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 382148 T2820 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 382148 T2820 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 382151 T2820 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 382166 T2820 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 382166 T2820 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-1393551059741/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393551053160/jetty3/
[junit4] 2> 382166 T2820 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7ead9935
[junit4] 2> 382167 T2820 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-1393551053160/jetty3
[junit4] 2> 382167 T2820 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393551053160/jetty3/index/
[junit4] 2> 382167 T2820 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393551053160/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 382167 T2820 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-1393551053160/jetty3/index
[junit4] 2> 382168 T2820 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=49, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 382172 T2820 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-1393551053160/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 382173 T2820 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 382176 T2820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 382176 T2820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 382177 T2820 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 382177 T2820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 382177 T2820 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 382178 T2820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 382178 T2820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 382178 T2820 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 382179 T2820 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 382179 T2820 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 382180 T2820 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 382180 T2820 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 382180 T2820 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 382181 T2820 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3
[...truncated too long message...]
SelectorImpl.doSelect(EPollSelectorImpl.java:90)
[junit4] 2> at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
[junit4] 2> at sun.nio.ch.SelectorImpl.selectNow(SelectorImpl.java:105)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:536)
[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> 65) Thread[id=2945, name=qtp312546516-2945 Selector1, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.nio.ch.IOUtil.drain(Native Method)
[junit4] 2> at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:90)
[junit4] 2> at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
[junit4] 2> at sun.nio.ch.SelectorImpl.selectNow(SelectorImpl.java:105)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:536)
[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> 66) Thread[id=3071, name=Thread-1489-SendThread(localhost.localdomain:49393), state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at java.lang.Thread.sleep(Native Method)
[junit4] 2> at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:86)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)
[junit4] 2> 67) Thread[id=2966, name=qtp1819308368-2966 Acceptor0 SslSelectChannelConnector@127.0.0.1:49883, 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> 68) Thread[id=3218, name=qtp1320495263-3218 Acceptor0 SslSelectChannelConnector@127.0.0.1:37983, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at org.eclipse.jetty.server.nio.SelectChannelConnector.getConnection(SelectChannelConnector.java:160)
[junit4] 2> at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:934)
[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> 69) Thread[id=3025, name=commitScheduler-1624-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.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081)
[junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
[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> 70) Thread[id=3063, name=qtp1849351551-3063 Acceptor0 SslSelectChannelConnector@127.0.0.1:57491, 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> 7598364 T2737 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/kq_m/nc,null}
[junit4] 2> NOTE: test params are: codec=HighCompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=140), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=140)), sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=nl_NL, timezone=Australia/Tasmania
[junit4] 2> NOTE: Linux 3.8.0-36-generic amd64/Oracle Corporation 1.8.0 (64-bit)/cpus=8,threads=78,free=353020928,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [FieldMutatingUpdateProcessorTest, TestCloudManagedSchemaAddField, TestFreeTextSuggestions, BasicDistributedZkTest, TestExtendedDismaxParser, BlockCacheTest, DeleteShardTest, ShardRoutingTest, LegacyHTMLStripCharFilterTest, ReturnFieldsTest, SliceStateTest, TestImplicitCoreProperties, TestLMDirichletSimilarityFactory, TestCollapseQParserPlugin, TestSystemIdResolver, TestRecoveryHdfs, AbstractAnalyticsStatsTest, PreAnalyzedUpdateProcessorTest, TestSearchPerf, DateMathParserTest, PrimitiveFieldTypeTest, TestFieldTypeCollectionResource, ExternalFileFieldSortTest, TestWriterPerf, SliceStateUpdateTest, TestMergePolicyConfig, TestDocumentBuilder, ResponseLogComponentTest, ZkControllerTest, LeaderElectionTest, UpdateRequestProcessorFactoryTest, AnalysisAfterCoreReloadTest, DocumentBuilderTest, TestSuggestSpellingConverter, TestRealTimeGet, TestJmxMonitoredMap, TestAddFieldRealTimeGet, TestJoin, HdfsSyncSliceTest, DistributedTermsComponentTest, TestNRTOpen, DistributedDebugComponentTest, SynonymTokenizerTest, TestSchemaSimilarityResource, TestLRUCache, HdfsRecoveryZkTest, FastVectorHighlighterTest, SolrIndexSplitterTest, HdfsBasicDistributedZk2Test, StatelessScriptUpdateProcessorFactoryTest, LoggingHandlerTest, SolrInfoMBeanTest, HdfsCollectionsAPIDistributedZkTest, TestPseudoReturnFields, TestSolrIndexConfig, TestGroupingSearch, TestAnalyzeInfixSuggestions, TestDocSet, TestSurroundQueryParser, HdfsChaosMonkeySafeLeaderTest, TestClassNameShortening, PolyFieldTest, QueryEqualityTest, TestLFUCache, SpellPossibilityIteratorTest, CoreAdminCreateDiscoverTest, TestCharFilters, BJQParserTest, SolrTestCaseJ4Test, TestCopyFieldCollectionResource, QueryElevationComponentTest, TermsComponentTest, TestReplicationHandler, BadComponentTest, DirectUpdateHandlerOptimizeTest, SOLR749Test, TestDocBasedVersionConstraints, DistributedQueryComponentCustomSortTest, ShowFileRequestHandlerTest, TestHighFrequencyDictionaryFactory, TestModifyConfFiles, LukeRequestHandlerTest, DistributedQueryElevationComponentTest, CopyFieldTest, TestCollationFieldDocValues, DocValuesTest, FileBasedSpellCheckerTest, QueryParsingTest, TestMaxScoreQueryParser, DOMUtilTest, ChaosMonkeySafeLeaderTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=E729C2CF22B5545B -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=nl_NL -Dtests.timezone=Australia/Tasmania -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([E729C2CF22B5545B]:0)
[junit4] Completed on J0 in 7225.33s, 1 test, 2 errors <<< FAILURES!
[...truncated 11 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:465: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:445: 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:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1274: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:907: There were test failures: 373 suites, 1607 tests, 1 suite-level error, 1 error, 47 ignored (19 assumptions)
Total time: 151 minutes 40 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0-fcs-b129 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure