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/06/29 08:10:47 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0_05) - Build #
10672 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10672/
Java: 32bit/jdk1.8.0_05 -client -XX:+UseG1GC
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([244A29F5AD9A6237]: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([244A29F5AD9A6237]:0)
Build Log:
[...truncated 12229 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/init-core-data-001
[junit4] 2> 553399 T2634 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
[junit4] 2> 553400 T2634 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 553403 T2634 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 553404 T2634 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 553405 T2635 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 553505 T2634 oasc.ZkTestServer.run start zk server on port:49348
[junit4] 2> 553506 T2634 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 558223 T2638 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 4716ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
[junit4] 2> 558226 T2641 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3595b0 name:ZooKeeperConnection Watcher:127.0.0.1:49348 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 558226 T2634 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 558227 T2634 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 558267 T2634 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 558276 T2643 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14668df name:ZooKeeperConnection Watcher:127.0.0.1:49348/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 558277 T2634 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 558277 T2634 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 558282 T2634 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 558285 T2634 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 558289 T2634 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 558293 T2634 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> 558295 T2634 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 558304 T2634 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> 558305 T2634 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 558310 T2634 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> 558312 T2634 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 558316 T2634 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> 558317 T2634 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 558321 T2634 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> 558322 T2634 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 558325 T2634 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> 558326 T2634 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 558330 T2634 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> 558331 T2634 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 558334 T2634 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> 558335 T2634 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 558339 T2634 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> 558340 T2634 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 558345 T2634 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> 558346 T2634 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 558350 T2634 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> 558351 T2634 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 558358 T2634 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 558360 T2645 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5141a name:ZooKeeperConnection Watcher:127.0.0.1:49348/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 558361 T2634 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 558659 T2634 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 558664 T2634 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 558669 T2634 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:58605
[junit4] 2> 558671 T2634 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 558672 T2634 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 558672 T2634 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-002
[junit4] 2> 558672 T2634 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-002/'
[junit4] 2> 558691 T2634 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-002/solr.xml
[junit4] 2> 558701 T2634 oasc.CoreContainer.<init> New CoreContainer 23722537
[junit4] 2> 558702 T2634 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-002/]
[junit4] 2> 558702 T2634 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 558703 T2634 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 558703 T2634 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 558703 T2634 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 558704 T2634 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 558704 T2634 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 558704 T2634 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 558704 T2634 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 558705 T2634 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 558707 T2634 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 558707 T2634 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 558707 T2634 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 558708 T2634 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49348/solr
[junit4] 2> 558708 T2634 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 558709 T2634 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 558710 T2656 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18e765d name:ZooKeeperConnection Watcher:127.0.0.1:49348 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 558711 T2634 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 558713 T2634 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 558714 T2658 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3cd4fd name:ZooKeeperConnection Watcher:127.0.0.1:49348/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 558715 T2634 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 558717 T2634 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 558721 T2634 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 558725 T2634 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 558729 T2634 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 558732 T2634 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 558737 T2634 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 558739 T2634 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58605_
[junit4] 2> 558741 T2634 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58605_
[junit4] 2> 558745 T2634 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 558749 T2634 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 558755 T2634 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:58605_
[junit4] 2> 558756 T2634 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 558759 T2634 oasc.Overseer.start Overseer (id=92013527124738052-127.0.0.1:58605_-n_0000000000) starting
[junit4] 2> 558764 T2634 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 558779 T2660 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 558780 T2634 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 558783 T2634 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 558786 T2634 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 558787 T2659 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 558789 T2661 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 558790 T2661 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 558790 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558791 T2661 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 558791 T2659 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 558792 T2659 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:58605",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:58605_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 558792 T2659 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 558792 T2659 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 558795 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558893 T2658 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> 559791 T2661 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 559791 T2661 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 559792 T2661 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 559792 T2661 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 559793 T2661 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 559794 T2661 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-002/collection1/'
[junit4] 2> 559794 T2661 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 559795 T2661 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 559795 T2661 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 559819 T2661 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 559832 T2661 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 559833 T2661 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 559839 T2661 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 559940 T2661 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 559942 T2661 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 559943 T2661 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 559945 T2661 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 559970 T2661 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 559971 T2661 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 559971 T2661 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-002/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/control/data/
[junit4] 2> 559971 T2661 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1e72456
[junit4] 2> 559972 T2661 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/control/data
[junit4] 2> 559972 T2661 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/control/data/index/
[junit4] 2> 559972 T2661 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 559973 T2661 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/control/data/index
[junit4] 2> 559973 T2661 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5350465672125199]
[junit4] 2> 559987 T2661 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/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 559987 T2661 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 559990 T2661 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 559990 T2661 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 559991 T2661 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 559991 T2661 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 559991 T2661 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 559991 T2661 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 559992 T2661 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 559992 T2661 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 559992 T2661 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 559993 T2661 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 559993 T2661 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 559993 T2661 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 559994 T2661 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 559994 T2661 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 559994 T2661 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 559995 T2661 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 559995 T2661 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 559997 T2661 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 559998 T2661 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 559998 T2661 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 559999 T2661 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=77.42578125, floorSegmentMB=1.916015625, forceMergeDeletesPctAllowed=14.246339402043423, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.10181610655398848
[junit4] 2> 560000 T2661 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/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 560000 T2661 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 560001 T2661 oass.SolrIndexSearcher.<init> Opening Searcher@10cb523[collection1] main
[junit4] 2> 560001 T2661 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 560002 T2661 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 560002 T2661 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 560003 T2661 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 560003 T2661 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 560003 T2661 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 560004 T2661 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 560004 T2661 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 560005 T2661 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 560005 T2661 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 560008 T2662 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@10cb523[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 560009 T2661 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 560010 T2665 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:58605 collection:control_collection shard:shard1
[junit4] 2> 560010 T2634 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 560011 T2665 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 560011 T2634 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 560014 T2634 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 560015 T2667 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ec53c0 name:ZooKeeperConnection Watcher:127.0.0.1:49348/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 560015 T2634 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 560016 T2634 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 560017 T2665 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 560018 T2634 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 560019 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560019 T2665 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 560019 T2665 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C797 name=collection1 org.apache.solr.core.SolrCore@7aa408 url=https://127.0.0.1:58605/collection1 node=127.0.0.1:58605_ C797_STATE=coll:control_collection core:collection1 props:{state=down, base_url=https://127.0.0.1:58605, core=collection1, node_name=127.0.0.1:58605_}
[junit4] 2> 560019 T2665 C797 P58605 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:58605/collection1/
[junit4] 2> 560020 T2665 C797 P58605 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 560020 T2665 C797 P58605 oasc.SyncStrategy.syncToMe https://127.0.0.1:58605/collection1/ has no replicas
[junit4] 2> 560020 T2665 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:58605/collection1/ shard1
[junit4] 2> 560020 T2665 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 560021 T2659 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 560023 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560024 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560026 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560128 T2667 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> 560128 T2658 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> 560175 T2665 oasc.ZkController.register We are https://127.0.0.1:58605/collection1/ and leader is https://127.0.0.1:58605/collection1/
[junit4] 2> 560176 T2665 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:58605
[junit4] 2> 560176 T2665 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 560176 T2665 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 560176 T2665 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 560178 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560179 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560179 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560179 T2665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 560180 T2659 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 560181 T2659 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:58605",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:58605_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 560185 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560287 T2667 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> 560287 T2658 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> 560292 T2634 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 560292 T2634 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 560296 T2634 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 560297 T2634 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:37444
[junit4] 2> 560299 T2634 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 560299 T2634 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 560300 T2634 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-003
[junit4] 2> 560300 T2634 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-003/'
[junit4] 2> 560315 T2634 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-003/solr.xml
[junit4] 2> 560325 T2634 oasc.CoreContainer.<init> New CoreContainer 26701645
[junit4] 2> 560326 T2634 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-003/]
[junit4] 2> 560326 T2634 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 560327 T2634 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 560327 T2634 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 560328 T2634 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 560328 T2634 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 560328 T2634 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 560328 T2634 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 560329 T2634 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 560329 T2634 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 560331 T2634 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 560332 T2634 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 560332 T2634 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 560333 T2634 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49348/solr
[junit4] 2> 560333 T2634 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 560334 T2634 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 560335 T2678 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1efa68d name:ZooKeeperConnection Watcher:127.0.0.1:49348 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 560335 T2634 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 560337 T2634 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 560338 T2680 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18dd1b4 name:ZooKeeperConnection Watcher:127.0.0.1:49348/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 560339 T2634 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 560344 T2634 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 561346 T2634 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37444_
[junit4] 2> 561347 T2634 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37444_
[junit4] 2> 561354 T2681 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 561354 T2681 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 561355 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561355 T2681 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 561355 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561356 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561356 T2659 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561357 T2659 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:37444",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37444_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 561357 T2659 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 561357 T2659 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 561359 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561462 T2658 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> 561462 T2680 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> 561462 T2667 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> 562356 T2681 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 562356 T2681 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 562357 T2681 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 562357 T2681 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 562358 T2681 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 562359 T2681 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-003/collection1/'
[junit4] 2> 562359 T2681 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 562360 T2681 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 562360 T2681 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 562383 T2681 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 562395 T2681 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 562396 T2681 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 562402 T2681 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 562514 T2681 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 562516 T2681 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 562517 T2681 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 562519 T2681 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 562532 T2681 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 562532 T2681 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 562533 T2681 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-003/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/jetty1/
[junit4] 2> 562533 T2681 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1e72456
[junit4] 2> 562533 T2681 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/jetty1
[junit4] 2> 562534 T2681 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/jetty1/index/
[junit4] 2> 562534 T2681 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 562534 T2681 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/jetty1/index
[junit4] 2> 562535 T2681 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5350465672125199]
[junit4] 2> 562541 T2681 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/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 562541 T2681 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 562545 T2681 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 562546 T2681 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 562546 T2681 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 562546 T2681 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 562546 T2681 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 562547 T2681 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 562547 T2681 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 562547 T2681 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 562547 T2681 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 562548 T2681 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 562549 T2681 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 562549 T2681 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 562549 T2681 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 562550 T2681 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 562550 T2681 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 562551 T2681 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 562551 T2681 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 562553 T2681 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 562554 T2681 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 562555 T2681 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 562556 T2681 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=77.42578125, floorSegmentMB=1.916015625, forceMergeDeletesPctAllowed=14.246339402043423, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.10181610655398848
[junit4] 2> 562557 T2681 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/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 562557 T2681 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 562557 T2681 oass.SolrIndexSearcher.<init> Opening Searcher@5b2a77[collection1] main
[junit4] 2> 562558 T2681 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 562559 T2681 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 562559 T2681 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 562559 T2681 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 562560 T2681 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 562560 T2681 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 562561 T2681 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 562561 T2681 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 562561 T2681 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 562562 T2681 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 562566 T2682 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5b2a77[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 562570 T2681 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 562570 T2685 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:37444 collection:collection1 shard:shard2
[junit4] 2> 562571 T2634 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 562571 T2634 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 562571 T2685 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 562576 T2685 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 562578 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562578 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562578 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562579 T2685 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 562579 T2685 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 562579 T2659 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C798 name=collection1 org.apache.solr.core.SolrCore@1b65750 url=https://127.0.0.1:37444/collection1 node=127.0.0.1:37444_ C798_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:37444, core=collection1, node_name=127.0.0.1:37444_}
[junit4] 2> 562579 T2685 C798 P37444 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:37444/collection1/
[junit4] 2> 562580 T2685 C798 P37444 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 562580 T2685 C798 P37444 oasc.SyncStrategy.syncToMe https://127.0.0.1:37444/collection1/ has no replicas
[junit4] 2> 562580 T2685 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:37444/collection1/ shard2
[junit4] 2> 562581 T2685 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 562581 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562587 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562590 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562691 T2667 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> 562691 T2658 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> 562692 T2680 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> 562738 T2685 oasc.ZkController.register We are https://127.0.0.1:37444/collection1/ and leader is https://127.0.0.1:37444/collection1/
[junit4] 2> 562738 T2685 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:37444
[junit4] 2> 562739 T2685 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 562739 T2685 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 562739 T2685 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 562741 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562741 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562741 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562742 T2685 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562742 T2659 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562743 T2659 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:37444",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37444_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 562744 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562842 T2634 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 562843 T2634 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 562846 T2634 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 562847 T2634 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:37335
[junit4] 2> 562848 T2634 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 562849 T2634 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 562849 T2667 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> 562849 T2680 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> 562849 T2658 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> 562849 T2634 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-004
[junit4] 2> 562851 T2634 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-004/'
[junit4] 2> 562864 T2634 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-004/solr.xml
[junit4] 2> 562874 T2634 oasc.CoreContainer.<init> New CoreContainer 20331455
[junit4] 2> 562875 T2634 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-004/]
[junit4] 2> 562875 T2634 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 562876 T2634 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 562876 T2634 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 562876 T2634 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 562877 T2634 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 562877 T2634 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 562877 T2634 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 562878 T2634 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 562878 T2634 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 562880 T2634 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 562880 T2634 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 562881 T2634 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 562881 T2634 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49348/solr
[junit4] 2> 562881 T2634 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 562882 T2634 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 562883 T2696 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@476912 name:ZooKeeperConnection Watcher:127.0.0.1:49348 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 562884 T2634 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 562886 T2634 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 562887 T2698 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ee8261 name:ZooKeeperConnection Watcher:127.0.0.1:49348/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 562887 T2634 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 562891 T2634 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 563894 T2634 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37335_
[junit4] 2> 563895 T2634 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37335_
[junit4] 2> 563902 T2699 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 563903 T2699 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 563904 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 563904 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 563904 T2699 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 563904 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 563905 T2659 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 563905 T2659 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:37335",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37335_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 563905 T2659 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 563906 T2659 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 563908 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 564009 T2667 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> 564009 T2698 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> 564009 T2658 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> 564009 T2680 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> 564904 T2699 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 564905 T2699 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 564906 T2699 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 564906 T2699 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 564906 T2699 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 564907 T2699 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-004/collection1/'
[junit4] 2> 564907 T2699 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 564908 T2699 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 564908 T2699 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 564932 T2699 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 564945 T2699 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 564947 T2699 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 564953 T2699 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 565067 T2699 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 565068 T2699 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 565069 T2699 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 565072 T2699 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 565087 T2699 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 565087 T2699 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 565088 T2699 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-004/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/jetty2/
[junit4] 2> 565088 T2699 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1e72456
[junit4] 2> 565089 T2699 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/jetty2
[junit4] 2> 565089 T2699 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/jetty2/index/
[junit4] 2> 565089 T2699 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 565090 T2699 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/jetty2/index
[junit4] 2> 565090 T2699 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5350465672125199]
[junit4] 2> 565095 T2699 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/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 565095 T2699 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 565099 T2699 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 565099 T2699 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 565099 T2699 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 565100 T2699 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 565100 T2699 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 565100 T2699 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 565100 T2699 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 565101 T2699 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 565101 T2699 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 565102 T2699 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 565102 T2699 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 565102 T2699 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 565103 T2699 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 565103 T2699 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 565104 T2699 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 565104 T2699 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 565105 T2699 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 565107 T2699 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 565108 T2699 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 565108 T2699 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 565109 T2699 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=77.42578125, floorSegmentMB=1.916015625, forceMergeDeletesPctAllowed=14.246339402043423, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.10181610655398848
[junit4] 2> 565110 T2699 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/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 565110 T2699 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 565111 T2699 oass.SolrIndexSearcher.<init> Opening Searcher@bb5c4a[collection1] main
[junit4] 2> 565111 T2699 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 565112 T2699 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 565112 T2699 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 565112 T2699 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 565113 T2699 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 565113 T2699 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 565113 T2699 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 565114 T2699 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 565114 T2699 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 565114 T2699 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 565118 T2700 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@bb5c4a[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 565122 T2699 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 565123 T2703 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:37335 collection:collection1 shard:shard3
[junit4] 2> 565123 T2634 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 565124 T2634 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 565124 T2703 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 565129 T2703 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
[junit4] 2> 565130 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 565131 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 565131 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 565131 T2703 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 565131 T2703 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 565131 T2659 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C799 name=collection1 org.apache.solr.core.SolrCore@f5d6a0 url=https://127.0.0.1:37335/collection1 node=127.0.0.1:37335_ C799_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:37335, core=collection1, node_name=127.0.0.1:37335_}
[junit4] 2> 565132 T2703 C799 P37335 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:37335/collection1/
[junit4] 2> 565132 T2703 C799 P37335 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 565132 T2703 C799 P37335 oasc.SyncStrategy.syncToMe https://127.0.0.1:37335/collection1/ has no replicas
[junit4] 2> 565132 T2703 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:37335/collection1/ shard3
[junit4] 2> 565133 T2703 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 565136 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 565138 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 565140 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 565242 T2667 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> 565242 T2698 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> 565242 T2658 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> 565242 T2680 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> 565289 T2703 oasc.ZkController.register We are https://127.0.0.1:37335/collection1/ and leader is https://127.0.0.1:37335/collection1/
[junit4] 2> 565289 T2703 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:37335
[junit4] 2> 565290 T2703 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 565290 T2703 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 565290 T2703 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 565291 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 565292 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 565292 T2703 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 565292 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 565293 T2659 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 565293 T2659 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:37335",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37335_",
[junit4] 2> "shard":"shard3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 565297 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 565398 T2667 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> 565399 T2698 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> 565398 T2658 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> 565398 T2680 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> 565424 T2634 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 565425 T2634 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 565427 T2634 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 565429 T2634 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:52697
[junit4] 2> 565430 T2634 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 565431 T2634 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 565431 T2634 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-005
[junit4] 2> 565431 T2634 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-005/'
[junit4] 2> 565445 T2634 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-005/solr.xml
[junit4] 2> 565455 T2634 oasc.CoreContainer.<init> New CoreContainer 7878163
[junit4] 2> 565456 T2634 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-005/]
[junit4] 2> 565456 T2634 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 565456 T2634 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 565457 T2634 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 565457 T2634 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 565457 T2634 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 565458 T2634 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 565458 T2634 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 565458 T2634 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 565459 T2634 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 565461 T2634 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 565461 T2634 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 565461 T2634 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 565462 T2634 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49348/solr
[junit4] 2> 565462 T2634 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 565463 T2634 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 565464 T2714 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10f9e1c name:ZooKeeperConnection Watcher:127.0.0.1:49348 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 565464 T2634 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 565466 T2634 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 565467 T2716 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11941df name:ZooKeeperConnection Watcher:127.0.0.1:49348/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 565467 T2634 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 565473 T2634 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 566475 T2634 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52697_
[junit4] 2> 566477 T2634 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52697_
[junit4] 2> 566488 T2717 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 566488 T2717 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 566489 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 566489 T2717 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 566489 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 566490 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 566491 T2659 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 566491 T2659 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:52697",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52697_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 566492 T2659 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 566492 T2659 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 566494 T2658 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 566598 T2667 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> 566598 T2716 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> 566598 T2698 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> 566598 T2680 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> 566598 T2658 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> 567490 T2717 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 567490 T2717 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 567491 T2717 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 567491 T2717 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 567492 T2717 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 567492 T2717 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-005/collection1/'
[junit4] 2> 567493 T2717 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-005/collection1/lib/.svn/' to classloader
[junit4] 2> 567494 T2717 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-005/collection1/lib/classes/' to classloader
[junit4] 2> 567494 T2717 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-244A29F5AD9A6237-001/tempDir-005/collection1/lib/README' to classloader
[junit4] 2> 567519 T2717 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 567531 T2717 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 567532 T2717 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 567539 T2717 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 567667 T2717 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 567669 T2717 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 567670 T2717 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 567672 T2717 oass.FileExchangeRateProvider
[...truncated too long message...]
nit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 96) Thread[id=3202, name=Thread-1285-SendThread(127.0.0.1:49348), state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at java.lang.Thread.sleep(Native Method)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:994)
[junit4] 2> 97) Thread[id=2705, name=qtp6080856-2705 Selector0, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:81)
[junit4] 2> at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 98) Thread[id=3127, name=qtp22423421-3127 Acceptor1 SslSelectChannelConnector@127.0.0.1:46338, state=BLOCKED, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at org.eclipse.jetty.server.nio.SelectChannelConnector.accept(SelectChannelConnector.java:102)
[junit4] 2> at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
[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:745)
[junit4] 2> 99) Thread[id=3063, name=searcherExecutor-2085-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 100) Thread[id=2682, name=searcherExecutor-1928-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 101) Thread[id=2689, name=qtp9735125-2689 Acceptor0 SslSelectChannelConnector@127.0.0.1:37335, state=BLOCKED, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at org.eclipse.jetty.server.nio.SelectChannelConnector.accept(SelectChannelConnector.java:102)
[junit4] 2> at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
[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:745)
[junit4] 2> 7778923 T2697 oaz.ClientCnxn$SendThread.run WARN Session 0x146e5d0becd0009 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4] 2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4] 2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:712)
[junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
[junit4] 2>
[junit4] 2> NOTE: test params are: codec=Lucene49: {rnd_b=PostingsFormat(name=Memory doPackFST= true), _version_=PostingsFormat(name=Direct), a_t=PostingsFormat(name=SimpleText), a_i=PostingsFormat(name=Memory doPackFST= true), id=PostingsFormat(name=Memory doPackFST= true)}, docValues:{}, sim=DefaultSimilarity, locale=ms_MY, timezone=Pacific/Auckland
[junit4] 2> NOTE: Linux 3.8.0-41-generic i386/Oracle Corporation 1.8.0_05 (32-bit)/cpus=8,threads=117,free=187912664,total=416284672
[junit4] 2> NOTE: All tests run in this JVM: [StatsComponentTest, BinaryUpdateRequestHandlerTest, TestUpdate, TestPHPSerializedResponseWriter, TestFiltering, TestIndexSearcher, TestReRankQParserPlugin, TestLRUCache, TestPostingsSolrHighlighter, FieldAnalysisRequestHandlerTest, TestIBSimilarityFactory, SpatialFilterTest, CoreContainerCoreInitFailuresTest, TestCollapseQParserPlugin, CopyFieldTest, TestRealTimeGet, TestPhraseSuggestions, TestQuerySenderNoQuery, SampleTest, SynonymTokenizerTest, AutoCommitTest, ResourceLoaderTest, TestAtomicUpdateErrorCases, SolrTestCaseJ4Test, TestMultiCoreConfBootstrap, CoreMergeIndexesAdminHandlerTest, CursorMarkTest, ConvertedLegacyTest, DistanceFunctionTest, TestDistributedGrouping, LukeRequestHandlerTest, TestShortCircuitedRequests, TestPerFieldSimilarity, TermVectorComponentTest, DirectUpdateHandlerOptimizeTest, UpdateRequestProcessorFactoryTest, TestLFUCache, TestSolrXml, DeleteReplicaTest, DeleteShardTest, TestBadConfig, SortByFunctionTest, RangeFacetTest, AddBlockUpdateTest, DistributedSuggestComponentTest, TestRestManager, LoggingHandlerTest, DistributedTermsComponentTest, MultiTermTest, TestWriterPerf, TestReloadAndDeleteDocs, TermVectorComponentDistributedTest, DocExpirationUpdateProcessorFactoryTest, RequestHandlersTest, TestNonDefinedSimilarityFactory, TestOmitPositions, TestIndexingPerformance, TestRandomFaceting, ChangedSchemaMergeTest, TestFreeTextSuggestions, SchemaVersionSpecificBehaviorTest, SuggestComponentTest, TestSystemIdResolver, DebugComponentTest, ScriptEngineTest, QueryParsingTest, CurrencyFieldXmlFileTest, AnalysisAfterCoreReloadTest, SolrCoreTest, ReplicationFactorTest, UUIDFieldTest, TestCollationField, TestReversedWildcardFilterFactory, TestSchemaSimilarityResource, TestSweetSpotSimilarityFactory, TestAddFieldRealTimeGet, TestSolrXMLSerializer, TestJoin, TestCollectionAPI, TestOrdValues, HdfsLockFactoryTest, TestElisionMultitermQuery, TestFieldResource, TestSolrXmlPersistence, SuggesterFSTTest, URLClassifyProcessorTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestRTGBase, IndexSchemaRuntimeFieldTest, SSLMigrationTest, ShardRoutingCustomTest, TestQueryTypes, SolrRequestParserTest, TestSuggestSpellingConverter, UniqFieldsUpdateProcessorFactoryTest, ClusterStateTest, SolrIndexConfigTest, TestUniqueKeyFieldResource, SimplePostToolTest, TestInfoStreamLogging, TestRecoveryHdfs, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=244A29F5AD9A6237 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ms_MY -Dtests.timezone=Pacific/Auckland -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J1 | ChaosMonkeySafeLeaderTest (suite) <<<
[junit4] > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4] > at __randomizedtesting.SeedInfo.seed([244A29F5AD9A6237]:0)
[junit4] Completed on J1 in 7225.60s, 1 test, 2 errors <<< FAILURES!
[...truncated 11 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: 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:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1298: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:922: There were test failures: 414 suites, 1702 tests, 1 suite-level error, 1 error, 36 ignored (15 assumptions)
Total time: 174 minutes 43 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0_05 -client -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any