Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/11824/
Java: 64bit/jdk1.9.0-ea-b34 -XX:-UseCompressedOops -XX:+UseG1GC (asserts: true)
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([78D62EC33B461E33]:0)
FAILED: 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([78D62EC33B461E33]:0)
Build Log:
[...truncated 10414 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-78D62EC33B461E33-001/init-core-data-001
[junit4] 2> 1691221 T5088 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl
(false) and clientAuth (false)
[junit4] 2> 1691221 T5088
oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system
property: /
[junit4] 2> 1691223 T5088 oas.SolrTestCaseJ4.setUp ###Starting
testDistribSearch
[junit4] 2> 1691224 T5088 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1691224 T5089 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1691324 T5088 oasc.ZkTestServer.run start zk server on
port:45567
[junit4] 2> 1691325 T5088
oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default
ZkCredentialsProvider
[junit4] 2> 1691325 T5088 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1691328 T5096 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@733c650b
name:ZooKeeperConnection Watcher:127.0.0.1:45567 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1691328 T5088 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1691329 T5088 oascc.SolrZkClient.createZkACLProvider Using
default ZkACLProvider
[junit4] 2> 1691329 T5088 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1691332 T5088
oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default
ZkCredentialsProvider
[junit4] 2> 1691333 T5088 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1691333 T5099 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7099daea
name:ZooKeeperConnection Watcher:127.0.0.1:45567/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1691334 T5088 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1691334 T5088 oascc.SolrZkClient.createZkACLProvider Using
default ZkACLProvider
[junit4] 2> 1691334 T5088 oascc.SolrZkClient.makePath makePath:
/collections/collection1
[junit4] 2> 1691336 T5088 oascc.SolrZkClient.makePath makePath:
/collections/collection1/shards
[junit4] 2> 1691338 T5088 oascc.SolrZkClient.makePath makePath:
/collections/control_collection
[junit4] 2> 1691339 T5088 oascc.SolrZkClient.makePath makePath:
/collections/control_collection/shards
[junit4] 2> 1691340 T5088 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> 1691340 T5088 oascc.SolrZkClient.makePath makePath:
/configs/conf1/solrconfig.xml
[junit4] 2> 1691342 T5088 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> 1691342 T5088 oascc.SolrZkClient.makePath makePath:
/configs/conf1/schema.xml
[junit4] 2> 1691343 T5088 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> 1691344 T5088 oascc.SolrZkClient.makePath makePath:
/configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1691345 T5088 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> 1691345 T5088 oascc.SolrZkClient.makePath makePath:
/configs/conf1/stopwords.txt
[junit4] 2> 1691346 T5088 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> 1691347 T5088 oascc.SolrZkClient.makePath makePath:
/configs/conf1/protwords.txt
[junit4] 2> 1691348 T5088 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> 1691348 T5088 oascc.SolrZkClient.makePath makePath:
/configs/conf1/currency.xml
[junit4] 2> 1691349 T5088 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> 1691349 T5088 oascc.SolrZkClient.makePath makePath:
/configs/conf1/enumsConfig.xml
[junit4] 2> 1691350 T5088 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> 1691350 T5088 oascc.SolrZkClient.makePath makePath:
/configs/conf1/open-exchange-rates.json
[junit4] 2> 1691351 T5088 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> 1691351 T5088 oascc.SolrZkClient.makePath makePath:
/configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1691352 T5088 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> 1691353 T5088 oascc.SolrZkClient.makePath makePath:
/configs/conf1/old_synonyms.txt
[junit4] 2> 1691353 T5088 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> 1691354 T5088 oascc.SolrZkClient.makePath makePath:
/configs/conf1/synonyms.txt
[junit4] 2> 1691593 T5088 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1691597 T5088 oejs.AbstractConnector.doStart Started
[email protected]:45168
[junit4] 2> 1691598 T5088 oass.SolrDispatchFilter.init
SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@4e0e2f2a
[junit4] 2> 1691598 T5088 oasc.SolrResourceLoader.locateSolrHome JNDI not
configured for solr (NoInitialContextEx)
[junit4] 2> 1691598 T5088 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-78D62EC33B461E33-001/tempDir-002
[junit4] 2> 1691598 T5088 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-78D62EC33B461E33-001/tempDir-002/'
[junit4] 2> 1691609 T5088 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-78D62EC33B461E33-001/tempDir-002/solr.xml
[junit4] 2> 1691618 T5088 oasc.CoreContainer.<init> New CoreContainer
46958647
[junit4] 2> 1691618 T5088 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-78D62EC33B461E33-001/tempDir-002/]
[junit4] 2> 1691619 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting socketTimeout to: 90000
[junit4] 2> 1691619 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting urlScheme to:
[junit4] 2> 1691619 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting connTimeout to: 15000
[junit4] 2> 1691619 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting maxConnectionsPerHost to: 20
[junit4] 2> 1691619 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting maxConnections to: 10000
[junit4] 2> 1691620 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting corePoolSize to: 0
[junit4] 2> 1691620 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting maximumPoolSize to: 2147483647
[junit4] 2> 1691620 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting maxThreadIdleTime to: 5
[junit4] 2> 1691620 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting sizeOfQueue to: -1
[junit4] 2> 1691621 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting fairnessPolicy to: false
[junit4] 2> 1691621 T5088 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 1691621 T5088 oasl.LogWatcher.createWatcher SLF4J impl is
org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1691621 T5088 oasl.LogWatcher.newRegisteredLogWatcher
Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1691622 T5088 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1691622 T5088 oasc.ZkContainer.initZooKeeper Zookeeper
client=127.0.0.1:45567/solr
[junit4] 2> 1691622 T5088 oasc.ZkController.checkChrootPath zkHost
includes chroot
[junit4] 2> 1691622 T5088
oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default
ZkCredentialsProvider
[junit4] 2> 1691623 T5088 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1691624 T5111 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@769452e5
name:ZooKeeperConnection Watcher:127.0.0.1:45567 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1691625 T5088 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1691626 T5088 oascc.SolrZkClient.createZkACLProvider Using
default ZkACLProvider
[junit4] 2> 1691628 T5088 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1691629 T5114 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@400284c name:ZooKeeperConnection
Watcher:127.0.0.1:45567/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1691629 T5088 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1691630 T5088 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1691633 T5088 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1691636 T5088 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1691639 T5088 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1691641 T5088 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1691645 T5088 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1691646 T5088 oasc.ZkController.createEphemeralLiveNode
Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45168_
[junit4] 2> 1691647 T5088 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1:45168_
[junit4] 2> 1691650 T5088 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1691652 T5088 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1691654 T5088 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1691656 T5088 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:45168_
[junit4] 2> 1691656 T5088 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1691658 T5088 oasc.Overseer.start Overseer
(id=93048725992570883-127.0.0.1:45168_-n_0000000000) starting
[junit4] 2> 1691661 T5088 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1691668 T5088 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1691669 T5116 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1691670 T5088 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1691673 T5088 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1691674 T5088
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1691680 T5115 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1691682 T5118 oasc.ZkController.publish publishing
core=collection1 state=down collection=control_collection
[junit4] 2> 1691682 T5118 oasc.ZkController.publish numShards not found on
descriptor - reading it from system property
[junit4] 2> 1691683 T5114 oasc.DistributedQueue$LatchWatcher.process
NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1691683 T5118 oasc.ZkController.waitForCoreNodeName look for
our core node name
[junit4] 2> 1691687 T5115 oasc.Overseer$ClusterStateUpdater.run
processMessage: queueSize: 0, message = {
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:45168";,
[junit4] 2> "node_name":"127.0.0.1:45168_",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 1691687 T5115 oasco.ReplicaMutator.updateState Update state
numShards=1 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:45168";,
[junit4] 2> "node_name":"127.0.0.1:45168_",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 1691688 T5115 oasco.ClusterStateMutator.createCollection
building a new cName: control_collection
[junit4] 2> 1691688 T5115 oasco.ReplicaMutator.updateState Assigning new
node to shard shard=shard1
[junit4] 2> 1691690 T5114 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> 1692684 T5118 oasc.ZkController.waitForShardId waiting to find
shard id in clusterstate for collection1
[junit4] 2> 1692685 T5118 oasc.ZkController.createCollectionZkNode Check
for collection zkNode:control_collection
[junit4] 2> 1692686 T5118 oasc.ZkController.createCollectionZkNode
Collection zkNode exists
[junit4] 2> 1692686 T5118 oascc.ZkStateReader.readConfigName Load
collection config from:/collections/control_collection
[junit4] 2> 1692688 T5118 oascc.ZkStateReader.readConfigName
path=/collections/control_collection configName=conf1 specified config exists
in ZooKeeper
[junit4] 2> 1692688 T5118 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-78D62EC33B461E33-001/tempDir-002/collection1/'
[junit4] 2> 1692689 T5118 oasc.SolrResourceLoader.replaceClassLoader
Adding
'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-002/collection1/lib/.svn/'
to classloader
[junit4] 2> 1692689 T5118 oasc.SolrResourceLoader.replaceClassLoader
Adding
'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-002/collection1/lib/classes/'
to classloader
[junit4] 2> 1692690 T5118 oasc.SolrResourceLoader.replaceClassLoader
Adding
'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-002/collection1/lib/README'
to classloader
[junit4] 2> 1692705 T5118 oasc.ZkController.watchZKConfDir watch zkdir
/configs/conf1
[junit4] 2> 1692708 T5118 oasc.Config.<init> loaded config solrconfig.xml
with version 0
[junit4] 2> 1692730 T5118 oasc.SolrConfig.<init> Using Lucene
MatchVersion: 6.0.0
[junit4] 2> 1692739 T5118 oasc.SolrConfig.<init> Loaded SolrConfig:
solrconfig.xml
[junit4] 2> 1692740 T5118 oass.IndexSchema.readSchema Reading Solr Schema
from /configs/conf1/schema.xml
[junit4] 2> 1692744 T5118 oass.IndexSchema.readSchema [collection1] Schema
name=test
[junit4] 2> 1692818 T5118 oass.IndexSchema.readSchema default search field
in schema is text
[junit4] 2> 1692819 T5118 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1692820 T5118 oass.FileExchangeRateProvider.reload Reloading
exchange rates from file currency.xml
[junit4] 2> 1692823 T5118 oass.FileExchangeRateProvider.reload Reloading
exchange rates from file currency.xml
[junit4] 2> 1692835 T5118 oasc.CoreContainer.create Creating SolrCore
'collection1' using configuration from collection control_collection
[junit4] 2> 1692836 T5118 oasc.SolrCore.initDirectoryFactory
solr.StandardDirectoryFactory
[junit4] 2> 1692836 T5118 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-78D62EC33B461E33-001/tempDir-002/collection1/,
dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/control/data/
[junit4] 2> 1692836 T5118 oasc.JmxMonitoredMap.<init> JMX monitoring is
enabled. Adding Solr mbeans to JMX Server:
com.sun.jmx.mbeanserver.JmxMBeanServer@7761cb42
[junit4] 2> 1692837 T5118 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-78D62EC33B461E33-001/tempDir-001/control/data
[junit4] 2> 1692837 T5118 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-78D62EC33B461E33-001/tempDir-001/control/data/index/
[junit4] 2> 1692837 T5118 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-78D62EC33B461E33-001/tempDir-001/control/data/index'
doesn't exist. Creating new index...
[junit4] 2> 1692838 T5118 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-78D62EC33B461E33-001/tempDir-001/control/data/index
[junit4] 2> 1692838 T5118 oasu.RandomMergePolicy.<init> RandomMergePolicy
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=50, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=37.7763671875,
floorSegmentMB=2.0107421875, forceMergeDeletesPctAllowed=22.637801835175402,
segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.7411699806539382
[junit4] 2> 1692920 T5118 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-78D62EC33B461E33-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 1692920 T5118 oasc.SolrDeletionPolicy.updateCommits newest
commit generation = 1
[junit4] 2> 1692924 T5118 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "nodistrib"
[junit4] 2> 1692925 T5118 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "dedupe"
[junit4] 2> 1692925 T5118 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1692925 T5118 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "stored_sig"
[junit4] 2> 1692926 T5118 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1692926 T5118 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1692926 T5118 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1692927 T5118 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 1692927 T5118 oasc.SolrCore.loadUpdateProcessorChains no
updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1692928 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /update: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1692928 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1692929 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1692929 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1692930 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /config: org.apache.solr.handler.SolrConfigHandler
[junit4] 2> 1692930 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /schema: org.apache.solr.handler.SchemaHandler
[junit4] 2> 1692931 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /replication: org.apache.solr.handler.ReplicationHandler
[junit4] 2> 1692931 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /get: org.apache.solr.handler.RealTimeGetHandler
[junit4] 2> 1692932 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /admin/luke: org.apache.solr.handler.admin.LukeRequestHandler
[junit4] 2> 1692932 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /admin/system: org.apache.solr.handler.admin.SystemInfoHandler
[junit4] 2> 1692933 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /admin/mbeans: org.apache.solr.handler.admin.SolrInfoMBeanHandler
[junit4] 2> 1692933 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /admin/plugins: org.apache.solr.handler.admin.PluginInfoHandler
[junit4] 2> 1692934 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /admin/threads: org.apache.solr.handler.admin.ThreadDumpHandler
[junit4] 2> 1692934 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /admin/properties:
org.apache.solr.handler.admin.PropertiesRequestHandler
[junit4] 2> 1692935 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /admin/logging: org.apache.solr.handler.admin.LoggingHandler
[junit4] 2> 1692935 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /admin/ping: org.apache.solr.handler.PingRequestHandler
[junit4] 2> 1692936 T5118 oasc.RequestHandlers.initHandlersFromConfig
created standard: solr.StandardRequestHandler
[junit4] 2> 1692936 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1692937 T5118 oasc.RequestHandlers.initHandlersFromConfig
created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 1692940 T5118 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1692941 T5118 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1692941 T5118 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1692942 T5118 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1692943 T5118 oasc.SolrCore.initStatsCache Using default
statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 1692943 T5118 oasu.CommitTracker.<init> Hard AutoCommit:
disabled
[junit4] 2> 1692943 T5118 oasu.CommitTracker.<init> Soft AutoCommit:
disabled
[junit4] 2> 1692944 T5118 oasu.RandomMergePolicy.<init> RandomMergePolicy
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=31, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=42.5185546875,
floorSegmentMB=0.412109375, forceMergeDeletesPctAllowed=5.14195774493436,
segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1692944 T5118 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-78D62EC33B461E33-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 1692945 T5118 oasc.SolrDeletionPolicy.updateCommits newest
commit generation = 1
[junit4] 2> 1692945 T5118 oass.SolrIndexSearcher.<init> Opening
Searcher@250ead58[collection1] main
[junit4] 2> 1692945 T5118 oascc.ZkStateReader.readConfigName Load
collection config from:/collections/control_collection
[junit4] 2> 1692946 T5118 oascc.ZkStateReader.readConfigName
path=/collections/control_collection configName=conf1 specified config exists
in ZooKeeper
[junit4] 2> 1692946 T5118 oasr.ManagedResourceStorage.newStorageIO Setting
up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1692947 T5118
oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured
ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1692947 T5118 oasr.RestManager.init Initializing RestManager
with initArgs: {}
[junit4] 2> 1692947 T5118 oasr.ManagedResourceStorage.load Reading
_rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1692948 T5118
oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found
for znode /configs/conf1/_rest_managed.json
[junit4] 2> 1692948 T5118 oasr.ManagedResourceStorage.load Loaded null at
path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1692948 T5118 oasr.RestManager.init Initializing 0 registered
ManagedResources
[junit4] 2> 1692948 T5118 oash.ReplicationHandler.inform Commits will be
reserved for 10000
[junit4] 2> 1692949 T5118 oasc.CoreContainer.registerCore registering
core: collection1
[junit4] 2> 1692949 T5119 oasc.SolrCore.registerSearcher [collection1]
Registered new searcher Searcher@250ead58[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1692949 T5122 oasc.ZkController.register Register replica -
core:collection1 address:http://127.0.0.1:45168 collection:control_collection
shard:shard1
[junit4] 2> 1692950 T5088 oass.SolrDispatchFilter.init
user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 1692950 T5088 oass.SolrDispatchFilter.init
SolrDispatchFilter.init() done
[junit4] 2> 1692951 T5122 oascc.SolrZkClient.makePath makePath:
/collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1692951 T5088
oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default
ZkCredentialsProvider
[junit4] 2> 1692952 T5088 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1692953 T5125 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5b00bb25
name:ZooKeeperConnection Watcher:127.0.0.1:45567/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1692953 T5088 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1692953 T5088 oascc.SolrZkClient.createZkACLProvider Using
default ZkACLProvider
[junit4] 2> 1692955 T5088
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1692956 T5122 oasc.ShardLeaderElectionContext.runLeaderProcess
Running the leader process for shard shard1
[junit4] 2> 1692957 T5114 oasc.DistributedQueue$LatchWatcher.process
NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1692957 T5088 oasc.ChaosMonkey.monkeyLog monkey: init - expire
sessions:false cause connection loss:false
[junit4] 2> 1692958 T5122
oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found
to continue.
[junit4] 2> 1692958 T5122 oasc.ShardLeaderElectionContext.runLeaderProcess
I may be the new leader - try and sync
[junit4] 2> 1692958 T5088 oasc.AbstractFullDistribZkTestBase.createJettys
Creating collection1 with stateFormat=2
[junit4] 2> ASYNC NEW_CORE C1073 name=collection1
org.apache.solr.core.SolrCore@59524b4a url=http://127.0.0.1:45168/collection1
node=127.0.0.1:45168_ C1073_STATE=coll:control_collection core:collection1
props:{core=collection1, base_url=http://127.0.0.1:45168,
node_name=127.0.0.1:45168_, state=down}
[junit4] 2> 1692958 T5122 C1073 P45168 oasc.SyncStrategy.sync Sync
replicas to http://127.0.0.1:45168/collection1/
[junit4] 2> 1692958 T5088
oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default
ZkCredentialsProvider
[junit4] 2> 1692958 T5115 oasc.Overseer$ClusterStateUpdater.run
processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection"} current state
version: 1
[junit4] 2> 1692958 T5122 C1073 P45168 oasc.SyncStrategy.syncReplicas Sync
Success - now sync replicas to me
[junit4] 2> 1692959 T5088 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1692959 T5122 C1073 P45168 oasc.SyncStrategy.syncToMe
http://127.0.0.1:45168/collection1/ has no replicas
[junit4] 2> 1692959 T5122 oasc.ShardLeaderElectionContext.runLeaderProcess
I am the new leader: http://127.0.0.1:45168/collection1/ shard1
[junit4] 2> 1692959 T5122 oascc.SolrZkClient.makePath makePath:
/collections/control_collection/leaders/shard1
[junit4] 2> 1692960 T5128 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5041fcd4
name:ZooKeeperConnection Watcher:127.0.0.1:45567/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1692960 T5088 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1692960 T5088 oascc.SolrZkClient.createZkACLProvider Using
default ZkACLProvider
[junit4] 2> 1692962 T5114 oasc.DistributedQueue$LatchWatcher.process
NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1692963 T5115 oasc.Overseer$ClusterStateUpdater.run
processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"create",
[junit4] 2> "name":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "stateFormat":2} current state version: 1
[junit4] 2> 1692963 T5115 oasco.ClusterStateMutator.createCollection
building a new cName: collection1
[junit4] 2> 1692964 T5114 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> 1692964 T5125 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> 1692968 T5115 oasc.Overseer$ClusterStateUpdater.run
processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "base_url":"http://127.0.0.1:45168";,
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"} current state version: 2
[junit4] 2> 1692969 T5115 oasco.ZkStateWriter.writePendingUpdates going to
create_collection /collections/collection1/state.json
[junit4] 2> 1692970 T5125 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> 1692973 T5129 oasc.DistributedQueue$LatchWatcher.process
NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1692973 T5125 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> 1693014 T5122 oasc.ZkController.register We are
http://127.0.0.1:45168/collection1/ and leader is
http://127.0.0.1:45168/collection1/
[junit4] 2> 1693014 T5122 oasc.ZkController.register No LogReplay needed
for core=collection1 baseURL=http://127.0.0.1:45168
[junit4] 2> 1693014 T5122 oasc.ZkController.checkRecovery I am the leader,
no recovery necessary
[junit4] 2> 1693014 T5122 oasc.ZkController.publish publishing
core=collection1 state=active collection=control_collection
[junit4] 2> 1693014 T5122 oasc.ZkController.publish numShards not found on
descriptor - reading it from system property
[junit4] 2> 1693015 T5114 oasc.DistributedQueue$LatchWatcher.process
NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1693016 T5115 oasc.Overseer$ClusterStateUpdater.run
processMessage: queueSize: 1, message = {
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:45168";,
[junit4] 2> "node_name":"127.0.0.1:45168_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"} current state version: 4
[junit4] 2> 1693017 T5115 oasco.ReplicaMutator.updateState Update state
numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:45168";,
[junit4] 2> "node_name":"127.0.0.1:45168_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 1693119 T5114 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> 1693119 T5125 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> 1693206 T5088 oasc.AbstractFullDistribZkTestBase.createJettys
create jetty 1
[junit4] 2> 1693207 T5088 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1693208 T5088 oejs.AbstractConnector.doStart Started
[email protected]:59892
[junit4] 2> 1693210 T5088 oass.SolrDispatchFilter.init
SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@4e0e2f2a
[junit4] 2> 1693210 T5088 oasc.SolrResourceLoader.locateSolrHome JNDI not
configured for solr (NoInitialContextEx)
[junit4] 2> 1693210 T5088 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-78D62EC33B461E33-001/tempDir-003
[junit4] 2> 1693211 T5088 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-78D62EC33B461E33-001/tempDir-003/'
[junit4] 2> 1693220 T5088 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-78D62EC33B461E33-001/tempDir-003/solr.xml
[junit4] 2> 1693245 T5088 oasc.CoreContainer.<init> New CoreContainer
564571002
[junit4] 2> 1693245 T5088 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-78D62EC33B461E33-001/tempDir-003/]
[junit4] 2> 1693246 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting socketTimeout to: 90000
[junit4] 2> 1693246 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting urlScheme to:
[junit4] 2> 1693247 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting connTimeout to: 15000
[junit4] 2> 1693247 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting maxConnectionsPerHost to: 20
[junit4] 2> 1693248 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting maxConnections to: 10000
[junit4] 2> 1693248 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting corePoolSize to: 0
[junit4] 2> 1693249 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting maximumPoolSize to: 2147483647
[junit4] 2> 1693249 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting maxThreadIdleTime to: 5
[junit4] 2> 1693250 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting sizeOfQueue to: -1
[junit4] 2> 1693250 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting fairnessPolicy to: false
[junit4] 2> 1693251 T5088 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 1693251 T5088 oasl.LogWatcher.createWatcher SLF4J impl is
org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1693252 T5088 oasl.LogWatcher.newRegisteredLogWatcher
Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1693252 T5088 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1693253 T5088 oasc.ZkContainer.initZooKeeper Zookeeper
client=127.0.0.1:45567/solr
[junit4] 2> 1693253 T5088 oasc.ZkController.checkChrootPath zkHost
includes chroot
[junit4] 2> 1693254 T5088
oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default
ZkCredentialsProvider
[junit4] 2> 1693255 T5088 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1693257 T5141 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1ecbac3f
name:ZooKeeperConnection Watcher:127.0.0.1:45567 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1693258 T5088 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1693259 T5088 oascc.SolrZkClient.createZkACLProvider Using
default ZkACLProvider
[junit4] 2> 1693262 T5088 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1693263 T5144 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5261b5c1
name:ZooKeeperConnection Watcher:127.0.0.1:45567/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1693263 T5088 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1693271 T5088
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1694276 T5088 oasc.ZkController.createEphemeralLiveNode
Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59892_
[junit4] 2> 1694277 T5088 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1:59892_
[junit4] 2> 1694284 T5088 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1694292 T5145 oasc.ZkController.publish publishing
core=collection1 state=down collection=collection1
[junit4] 2> 1694292 T5145 oasc.ZkController.publish numShards not found on
descriptor - reading it from system property
[junit4] 2> 1694294 T5114 oasc.DistributedQueue$LatchWatcher.process
NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1694295 T5145 oasc.ZkController.preRegister Registering watch
for external collection collection1
[junit4] 2> 1694296 T5115 oasc.Overseer$ClusterStateUpdater.run
processMessage: queueSize: 1, message = {
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:59892";,
[junit4] 2> "node_name":"127.0.0.1:59892_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"} current state version: 5
[junit4] 2> 1694296 T5145 oascc.ZkStateReader.addZkWatch addZkWatch
collection1
[junit4] 2> 1694296 T5115 oasco.ReplicaMutator.updateState Update state
numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:59892";,
[junit4] 2> "node_name":"127.0.0.1:59892_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 1694297 T5145 oascc.ZkStateReader.addZkWatch Updating
collection state at /collections/collection1/state.json from ZooKeeper...
[junit4] 2> 1694297 T5115 oasco.ReplicaMutator.updateState Collection
already exists with numShards=2
[junit4] 2> 1694297 T5115 oasco.ReplicaMutator.updateState Assigning new
node to shard shard=shard2
[junit4] 2> 1694298 T5145 oascc.ZkStateReader.updateWatchedCollection
Updating data for collection1 to ver 0
[junit4] 2> 1694299 T5145 oasc.ZkController.waitForCoreNodeName look for
our core node name
[junit4] 2> 1694401 T5115 oasco.ZkStateWriter.writePendingUpdates going to
update_collection /collections/collection1/state.json version: 0
[junit4] 2> 1694402 T5144 oascc.ZkStateReader$7.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1694403 T5144 oascc.ZkStateReader.updateWatchedCollection
Updating data for collection1 to ver 1
[junit4] 2> 1695299 T5145 oasc.ZkController.waitForShardId waiting to find
shard id in clusterstate for collection1
[junit4] 2> 1695300 T5145 oasc.ZkController.createCollectionZkNode Check
for collection zkNode:collection1
[junit4] 2> 1695301 T5145 oasc.ZkController.createCollectionZkNode
Collection zkNode exists
[junit4] 2> 1695301 T5145 oascc.ZkStateReader.readConfigName Load
collection config from:/collections/collection1
[junit4] 2> 1695302 T5145 oascc.ZkStateReader.readConfigName
path=/collections/collection1 configName=conf1 specified config exists in
ZooKeeper
[junit4] 2> 1695303 T5145 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-78D62EC33B461E33-001/tempDir-003/collection1/'
[junit4] 2> 1695304 T5145 oasc.SolrResourceLoader.replaceClassLoader
Adding
'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-003/collection1/lib/.svn/'
to classloader
[junit4] 2> 1695304 T5145 oasc.SolrResourceLoader.replaceClassLoader
Adding
'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-003/collection1/lib/classes/'
to classloader
[junit4] 2> 1695305 T5145 oasc.SolrResourceLoader.replaceClassLoader
Adding
'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-003/collection1/lib/README'
to classloader
[junit4] 2> 1695322 T5145 oasc.ZkController.watchZKConfDir watch zkdir
/configs/conf1
[junit4] 2> 1695324 T5145 oasc.Config.<init> loaded config solrconfig.xml
with version 0
[junit4] 2> 1695333 T5145 oasc.SolrConfig.<init> Using Lucene
MatchVersion: 6.0.0
[junit4] 2> 1695343 T5145 oasc.SolrConfig.<init> Loaded SolrConfig:
solrconfig.xml
[junit4] 2> 1695345 T5145 oass.IndexSchema.readSchema Reading Solr Schema
from /configs/conf1/schema.xml
[junit4] 2> 1695349 T5145 oass.IndexSchema.readSchema [collection1] Schema
name=test
[junit4] 2> 1695434 T5145 oass.IndexSchema.readSchema default search field
in schema is text
[junit4] 2> 1695435 T5145 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1695436 T5145 oass.FileExchangeRateProvider.reload Reloading
exchange rates from file currency.xml
[junit4] 2> 1695439 T5145 oass.FileExchangeRateProvider.reload Reloading
exchange rates from file currency.xml
[junit4] 2> 1695457 T5145 oasc.CoreContainer.create Creating SolrCore
'collection1' using configuration from collection collection1
[junit4] 2> 1695458 T5145 oasc.SolrCore.initDirectoryFactory
solr.StandardDirectoryFactory
[junit4] 2> 1695458 T5145 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-78D62EC33B461E33-001/tempDir-003/collection1/,
dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty1/
[junit4] 2> 1695458 T5145 oasc.JmxMonitoredMap.<init> JMX monitoring is
enabled. Adding Solr mbeans to JMX Server:
com.sun.jmx.mbeanserver.JmxMBeanServer@7761cb42
[junit4] 2> 1695459 T5145 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-78D62EC33B461E33-001/tempDir-001/jetty1
[junit4] 2> 1695459 T5145 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-78D62EC33B461E33-001/tempDir-001/jetty1/index/
[junit4] 2> 1695459 T5145 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-78D62EC33B461E33-001/tempDir-001/jetty1/index'
doesn't exist. Creating new index...
[junit4] 2> 1695461 T5145 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-78D62EC33B461E33-001/tempDir-001/jetty1/index
[junit4] 2> 1695461 T5145 oasu.RandomMergePolicy.<init> RandomMergePolicy
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=50, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=37.7763671875,
floorSegmentMB=2.0107421875, forceMergeDeletesPctAllowed=22.637801835175402,
segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.7411699806539382
[junit4] 2> 1695471 T5145 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-78D62EC33B461E33-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 1695471 T5145 oasc.SolrDeletionPolicy.updateCommits newest
commit generation = 1
[junit4] 2> 1695473 T5145 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "nodistrib"
[junit4] 2> 1695473 T5145 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "dedupe"
[junit4] 2> 1695473 T5145 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1695473 T5145 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "stored_sig"
[junit4] 2> 1695473 T5145 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1695474 T5145 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1695474 T5145 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1695474 T5145 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 1695474 T5145 oasc.SolrCore.loadUpdateProcessorChains no
updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1695474 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /update: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1695475 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1695475 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1695475 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1695475 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /config: org.apache.solr.handler.SolrConfigHandler
[junit4] 2> 1695476 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /schema: org.apache.solr.handler.SchemaHandler
[junit4] 2> 1695477 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /replication: org.apache.solr.handler.ReplicationHandler
[junit4] 2> 1695477 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /get: org.apache.solr.handler.RealTimeGetHandler
[junit4] 2> 1695478 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /admin/luke: org.apache.solr.handler.admin.LukeRequestHandler
[junit4] 2> 1695478 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /admin/system: org.apache.solr.handler.admin.SystemInfoHandler
[junit4] 2> 1695478 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /admin/mbeans: org.apache.solr.handler.admin.SolrInfoMBeanHandler
[junit4] 2> 1695479 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /admin/plugins: org.apache.solr.handler.admin.PluginInfoHandler
[junit4] 2> 1695479 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /admin/threads: org.apache.solr.handler.admin.ThreadDumpHandler
[junit4] 2> 1695479 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /admin/properties:
org.apache.solr.handler.admin.PropertiesRequestHandler
[junit4] 2> 1695480 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /admin/logging: org.apache.solr.handler.admin.LoggingHandler
[junit4] 2> 1695480 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /admin/ping: org.apache.solr.handler.PingRequestHandler
[junit4] 2> 1695480 T5145 oasc.RequestHandlers.initHandlersFromConfig
created standard: solr.StandardRequestHandler
[junit4] 2> 1695481 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1695481 T5145 oasc.RequestHandlers.initHandlersFromConfig
created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 1695483 T5145 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1695484 T5145 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1695485 T5145 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1695486 T5145 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1695487 T5145 oasc.SolrCore.initStatsCache Using default
statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 1695488 T5145 oasu.CommitTracker.<init> Hard AutoCommit:
disabled
[junit4] 2> 1695488 T5145 oasu.CommitTracker.<init> Soft AutoCommit:
disabled
[junit4] 2> 1695489 T5145 oasu.RandomMergePolicy.<init> RandomMergePolicy
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=31, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=42.5185546875,
floorSegmentMB=0.412109375, forceMergeDeletesPctAllowed=5.14195774493436,
segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1695490 T5145 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-78D62EC33B461E33-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 1695490 T5145 oasc.SolrDeletionPolicy.updateCommits newest
commit generation = 1
[junit4] 2> 1695490 T5145 oass.SolrIndexSearcher.<init> Opening
Searcher@3846d997[collection1] main
[junit4] 2> 1695491 T5145 oascc.ZkStateReader.readConfigName Load
collection config from:/collections/collection1
[junit4] 2> 1695492 T5145 oascc.ZkStateReader.readConfigName
path=/collections/collection1 configName=conf1 specified config exists in
ZooKeeper
[junit4] 2> 1695492 T5145 oasr.ManagedResourceStorage.newStorageIO Setting
up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1695493 T5145
oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured
ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1695493 T5145 oasr.RestManager.init Initializing RestManager
with initArgs: {}
[junit4] 2> 1695494 T5145 oasr.ManagedResourceStorage.load Reading
_rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1695494 T5145
oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found
for znode /configs/conf1/_rest_managed.json
[junit4] 2> 1695495 T5145 oasr.ManagedResourceStorage.load Loaded null at
path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1695495 T5145 oasr.RestManager.init Initializing 0 registered
ManagedResources
[junit4] 2> 1695495 T5145 oash.ReplicationHandler.inform Commits will be
reserved for 10000
[junit4] 2> 1695496 T5146 oasc.SolrCore.registerSearcher [collection1]
Registered new searcher Searcher@3846d997[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1695497 T5145 oasc.CoreContainer.registerCore registering
core: collection1
[junit4] 2> 1695498 T5149 oasc.ZkController.register Register replica -
core:collection1 address:http://127.0.0.1:59892 collection:collection1
shard:shard2
[junit4] 2> 1695498 T5088 oass.SolrDispatchFilter.init
user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 1695499 T5088 oass.SolrDispatchFilter.init
SolrDispatchFilter.init() done
[junit4] 2> 1695499 T5149 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 1695505 T5149 oasc.ShardLeaderElectionContext.runLeaderProcess
Running the leader process for shard shard2
[junit4] 2> 1695507 T5114 oasc.DistributedQueue$LatchWatcher.process
NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1695507 T5149
oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found
to continue.
[junit4] 2> 1695507 T5149 oasc.ShardLeaderElectionContext.runLeaderProcess
I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1074 name=collection1
org.apache.solr.core.SolrCore@225a108e url=http://127.0.0.1:59892/collection1
node=127.0.0.1:59892_ C1074_STATE=coll:collection1 core:collection1
props:{core=collection1, base_url=http://127.0.0.1:59892,
node_name=127.0.0.1:59892_, state=down}
[junit4] 2> 1695508 T5149 C1074 P59892 oasc.SyncStrategy.sync Sync
replicas to http://127.0.0.1:59892/collection1/
[junit4] 2> 1695508 T5115 oasc.Overseer$ClusterStateUpdater.run
processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1"} current state version: 5
[junit4] 2> 1695508 T5149 C1074 P59892 oasc.SyncStrategy.syncReplicas Sync
Success - now sync replicas to me
[junit4] 2> 1695509 T5149 C1074 P59892 oasc.SyncStrategy.syncToMe
http://127.0.0.1:59892/collection1/ has no replicas
[junit4] 2> 1695509 T5149 oasc.ShardLeaderElectionContext.runLeaderProcess
I am the new leader: http://127.0.0.1:59892/collection1/ shard2
[junit4] 2> 1695509 T5149 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard2
[junit4] 2> 1695510 T5115 oasco.ZkStateWriter.writePendingUpdates going to
update_collection /collections/collection1/state.json version: 1
[junit4] 2> 1695510 T5144 oascc.ZkStateReader$7.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1695511 T5144 oascc.ZkStateReader.updateWatchedCollection
Updating data for collection1 to ver 2
[junit4] 2> 1695513 T5114 oasc.DistributedQueue$LatchWatcher.process
NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1695514 T5115 oasc.Overseer$ClusterStateUpdater.run
processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"http://127.0.0.1:59892";,
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"} current state version: 5
[junit4] 2> 1695515 T5115 oasco.ZkStateWriter.writePendingUpdates going to
update_collection /collections/collection1/state.json version: 2
[junit4] 2> 1695515 T5144 oascc.ZkStateReader$7.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1695515 T5144 oascc.ZkStateReader.updateWatchedCollection
Updating data for collection1 to ver 3
[junit4] 2> 1695564 T5149 oasc.ZkController.register We are
http://127.0.0.1:59892/collection1/ and leader is
http://127.0.0.1:59892/collection1/
[junit4] 2> 1695564 T5149 oasc.ZkController.register No LogReplay needed
for core=collection1 baseURL=http://127.0.0.1:59892
[junit4] 2> 1695564 T5149 oasc.ZkController.checkRecovery I am the leader,
no recovery necessary
[junit4] 2> 1695564 T5149 oasc.ZkController.publish publishing
core=collection1 state=active collection=collection1
[junit4] 2> 1695564 T5149 oasc.ZkController.publish numShards not found on
descriptor - reading it from system property
[junit4] 2> 1695566 T5114 oasc.DistributedQueue$LatchWatcher.process
NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1695566 T5115 oasc.Overseer$ClusterStateUpdater.run
processMessage: queueSize: 1, message = {
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:59892";,
[junit4] 2> "node_name":"127.0.0.1:59892_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"} current state version: 5
[junit4] 2> 1695567 T5115 oasco.ReplicaMutator.updateState Update state
numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:59892";,
[junit4] 2> "node_name":"127.0.0.1:59892_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 1695568 T5115 oasco.ZkStateWriter.writePendingUpdates going to
update_collection /collections/collection1/state.json version: 3
[junit4] 2> 1695569 T5149 oascc.ZkStateReader.updateWatchedCollection
Updating data for collection1 to ver 3
[junit4] 2> 1695569 T5144 oascc.ZkStateReader$7.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1695569 T5144 oascc.ZkStateReader.updateWatchedCollection
Updating data for collection1 to ver 4
[junit4] 2> 1695738 T5088 oasc.AbstractFullDistribZkTestBase.createJettys
create jetty 2
[junit4] 2> 1695739 T5088 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1695740 T5088 oejs.AbstractConnector.doStart Started
[email protected]:40753
[junit4] 2> 1695742 T5088 oass.SolrDispatchFilter.init
SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@4e0e2f2a
[junit4] 2> 1695742 T5088 oasc.SolrResourceLoader.locateSolrHome JNDI not
configured for solr (NoInitialContextEx)
[junit4] 2> 1695742 T5088 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-78D62EC33B461E33-001/tempDir-004
[junit4] 2> 1695743 T5088 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-78D62EC33B461E33-001/tempDir-004/'
[junit4] 2> 1695752 T5088 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-78D62EC33B461E33-001/tempDir-004/solr.xml
[junit4] 2> 1695759 T5088 oasc.CoreContainer.<init> New CoreContainer
1880290833
[junit4] 2> 1695760 T5088 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-78D62EC33B461E33-001/tempDir-004/]
[junit4] 2> 1695760 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting socketTimeout to: 90000
[junit4] 2> 1695760 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting urlScheme to:
[junit4] 2> 1695760 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting connTimeout to: 15000
[junit4] 2> 1695761 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting maxConnectionsPerHost to: 20
[junit4] 2> 1695761 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting maxConnections to: 10000
[junit4] 2> 1695761 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting corePoolSize to: 0
[junit4] 2> 1695761 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting maximumPoolSize to: 2147483647
[junit4] 2> 1695762 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting maxThreadIdleTime to: 5
[junit4] 2> 1695762 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting sizeOfQueue to: -1
[junit4] 2> 1695762 T5088 oashc.HttpShardHandlerFactory.getParameter
Setting fairnessPolicy to: false
[junit4] 2> 1695762 T5088 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 1695763 T5088 oasl.LogWatcher.createWatcher SLF4J impl is
org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1695763 T5088 oasl.LogWatcher.newRegisteredLogWatcher
Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1695763 T5088 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1695763 T5088 oasc.ZkContainer.initZooKeeper Zookeeper
client=127.0.0.1:45567/solr
[junit4] 2> 1695763 T5088 oasc.ZkController.checkChrootPath zkHost
includes chroot
[junit4] 2> 1695764 T5088
oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default
ZkCredentialsProvider
[junit4] 2> 1695764 T5088 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1695766 T5161 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7429b92f
name:ZooKeeperConnection Watcher:127.0.0.1:45567 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1695768 T5088 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1695768 T5088 oascc.SolrZkClient.createZkACLProvider Using
default ZkACLProvider
[junit4] 2> 1695770 T5088 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1695772 T5164 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5599d13c
name:ZooKeeperConnection Watcher:127.0.0.1:45567/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1695772 T5088 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1695778 T5088
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1696784 T5088 oasc.ZkController.createEphemeralLiveNode
Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40753_
[junit4] 2> 1696785 T5088 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1:40753_
[junit4] 2> 1696792 T5088 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1696799 T5165 oasc.ZkController.publish publishing
core=collection1 state=down collection=collection1
[junit4] 2> 1696800 T5165 oasc.ZkController.publish numShards not found on
descriptor - reading it from system property
[junit4] 2> 1696802 T5114 oasc.DistributedQueue$LatchWatcher.process
NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1696803 T5165 oasc.ZkController.preRegister Registering watch
for external collection collection1
[junit4] 2> 1696803 T5165 oascc.ZkStateReader.addZkWatch addZkWatch
collection1
[junit4] 2> 1696804 T5115 oasc.Overseer$ClusterStateUpdater.run
processMessage: queueSize: 1, message = {
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:40753";,
[junit4] 2> "node_name":"127.0.0.1:40753_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"} current state version: 5
[junit4] 2> 1696804 T5165 oascc.ZkStateReader.addZkWatch Updating
collection state at /collections/collection1/state.json from ZooKeeper...
[junit4] 2> 1696805 T5115 oasco.ReplicaMutator.updateState Update state
numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:40753";,
[junit4] 2> "node_name":"127.0.0.1:40753_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 1696805 T5115 oasco.ReplicaMutator.updateState Collection
already exists with numShards=2
[junit4] 2> 1696805 T5115 oasco.ReplicaMutator.updateState Assigning new
node to shard shard=shard1
[junit4] 2> 1696806 T5165 oascc.ZkStateReader.updateWatchedCollection
Updating data for collection1 to ver 4
[junit4] 2> 1696806 T5165 oasc.ZkController.waitForCoreNodeName look for
our core node name
[junit4] 2> 1696807 T5115 oasco.ZkStateWriter.writePendingUpdates going to
update_collection /collections/collection1/state.json version: 4
[junit4] 2> 1696807 T5144 oascc.ZkStateReader$7.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1696807 T5164 oascc.ZkStateReader$7.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1696808 T5144 oascc.ZkStateReader.updateWatchedCollection
Updating data for collection1 to ver 5
[junit4] 2> 1696808 T5164 oascc.ZkStateReader.updateWatchedCollection
Updating data for collection1 to ver 5
[junit4] 2> 1697806 T5165 oasc.ZkController.waitForShardId waiting to find
shard id in clusterstate for collection1
[junit4] 2> 1697807 T5165 oasc.ZkController.createCollectionZkNode Check
for collection zkNode:collection1
[junit4] 2> 1697808 T5165 oasc.ZkController.createCollectionZkNode
Collection zkNode exists
[junit4] 2> 1697808 T5165 oascc.ZkStateReader.readConfigName Load
collection config from:/collections/collection1
[junit4] 2> 1697809 T5165 oascc.ZkStateReader.readConfigName
path=/collections/collection1 configName=conf1 specified config exists in
ZooKeeper
[junit4] 2> 1697809 T5165 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-78D62EC33B461E33-001/tempDir-004/collection1/'
[junit4] 2> 1697810 T5165 oasc.SolrResourceLoader.replaceClassLoader
Adding
'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-004/collection1/lib/.svn/'
to classloader
[junit4] 2> 1697810 T5165 oasc.SolrResourceLoader.replaceClassLoader
Adding
'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-004/collection1/lib/classes/'
to classloader
[junit4] 2> 1697811 T5165 oasc.SolrResourceLoader.replaceClassLoader
Adding
'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-004/collection1/lib/README'
to classloader
[junit4] 2> 1697825 T5165 oasc.ZkController.watchZKConfDir watch zkdir
/configs/conf1
[junit4] 2> 1697828 T5165 oasc.Config.<init> loaded config solrconfig.xml
with version 0
[junit4] 2> 1697836 T5165 oasc.SolrConfig.<init> Using Lucene
MatchVersion: 6.0.0
[junit4] 2> 1697846 T5165 oasc.SolrConfig.<init> Loaded SolrConfig:
solrconfig.xml
[junit4] 2> 1697847 T5165 oass.IndexSchema.readSchema Reading Solr Schema
from /configs/conf1/schema.xml
[junit4] 2> 1697851 T5165 oass.IndexSchema.readSchema [collection1] Schema
name=test
[junit4] 2> 1697950 T5165 oass.IndexSchema.readSchema default search field
in schema is text
[junit4] 2> 1697951 T5165 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1697951 T5165 oass.FileExchangeRateProvider.reload Reloading
exchange rates from file currency.xml
[junit4] 2> 1697954 T5165 oass.FileExchangeRateProvider.reload Reloading
exchange rates from file currency.xml
[junit4] 2> 1697972 T5165 oasc.CoreContainer.create Creating SolrCore
'collection1' using configuration from collection collection1
[junit4] 2> 1697972 T5165 oasc.SolrCore.initDirectoryFactory
solr.StandardDirectoryFactory
[junit4] 2> 1697972 T5165 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-78D62EC33B461E33-001/tempDir-004/collection1/,
dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty2/
[junit4] 2> 1697972 T5165 oasc.JmxMonitoredMap.<init> JMX monitoring is
enabled. Adding Solr mbeans to JMX Server:
com.sun.jmx.mbeanserver.JmxMBeanServer@7761cb42
[junit4] 2> 1697973 T5165 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-78D62EC33B461E33-001/tempDir-001/jetty2
[junit4] 2> 1697973 T5165 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-78D62EC33B461E33-001/tempDir-001/jetty2/index/
[junit4] 2> 1697973 T5165 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-78D62EC33B461E33-001/tempDir-001/jetty2/index'
doesn't exist. Creating new index...
[junit4] 2> 1697975 T5165 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-78D62EC33B461E33-001/tempDir-001/jetty2/index
[junit4] 2> 1697975 T5165 oasu.RandomMergePolicy.<init> RandomMergePolicy
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=50, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=37.7763671875,
floorSegmentMB=2.0107421875, forceMergeDeletesPctAllowed=22.637801835175402,
segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.7411699806539382
[junit4] 2> 1697983 T5165 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-78D62EC33B461E33-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 1697984 T5165 oasc.SolrDeletionPolicy.updateCommits newest
commit generation = 1
[junit4] 2> 1697988 T5165 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "nodistrib"
[junit4] 2> 1697988 T5165 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "dedupe"
[junit4] 2> 1697989 T5165 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1697989 T5165 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "stored_sig"
[junit4] 2> 1697989 T5165 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1697990 T5165 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1697990 T5165 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1697990 T5165 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 1697991 T5165 oasc.SolrCore.loadUpdateProcessorChains no
updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1697991 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /update: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1697992 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1697992 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1697993 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1697993 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /config: org.apache.solr.handler.SolrConfigHandler
[junit4] 2> 1697994 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /schema: org.apache.solr.handler.SchemaHandler
[junit4] 2> 1697996 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /replication: org.apache.solr.handler.ReplicationHandler
[junit4] 2> 1697997 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /get: org.apache.solr.handler.RealTimeGetHandler
[junit4] 2> 1697997 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /admin/luke: org.apache.solr.handler.admin.LukeRequestHandler
[junit4] 2> 1697998 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /admin/system: org.apache.solr.handler.admin.SystemInfoHandler
[junit4] 2> 1697999 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /admin/mbeans: org.apache.solr.handler.admin.SolrInfoMBeanHandler
[junit4] 2> 1697999 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /admin/plugins: org.apache.solr.handler.admin.PluginInfoHandler
[junit4] 2> 1698000 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /admin/threads: org.apache.solr.handler.admin.ThreadDumpHandler
[junit4] 2> 1698000 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /admin/properties:
org.apache.solr.handler.admin.PropertiesRequestHandler
[junit4] 2> 1698001 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /admin/logging: org.apache.solr.handler.admin.LoggingHandler
[junit4] 2> 1698001 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /admin/ping: org.apache.solr.handler.PingRequestHandler
[junit4] 2> 1698002 T5165 oasc.RequestHandlers.initHandlersFromConfig
created standard: solr.StandardRequestHandler
[junit4] 2> 1698002 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1698002 T5165 oasc.RequestHandlers.initHandlersFromConfig
created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 1698004 T5165 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1698004 T5165 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1698005 T5165 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1698006 T5165 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1698006 T5165 oasc.SolrCore.initStatsCache Using default
statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 1698007 T5165 oasu.CommitTracker.<init> Hard AutoCommit:
disabled
[junit4] 2> 1698007 T5165 oasu.CommitTracker.<init> Soft AutoCommit:
disabled
[junit4] 2> 1698007 T5165 oasu.RandomMergePolicy.<init> RandomMergePolicy
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=31, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=42.5185546875,
floorSegmentMB=0.412109375, forceMergeDeletesPctAllowed=5.14195774493436,
segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1698008 T5165 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-78D62EC33B461E33-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 1698008 T5165 oasc.SolrDeletionPolicy.updateCommits newest
commit generation = 1
[junit4] 2> 1698008 T5165 oass.SolrIndexSearcher.<init> Opening
Searcher@2b95bec[collection1] main
[junit4] 2> 1698009 T5165 oascc.ZkStateReader.readConfigName Load
collection config from:/collections/collection1
[junit4] 2> 1698010 T5165 oascc.ZkStateReader.readConfigName
path=/collections/collection1 configName=conf1 specified config exists in
ZooKeeper
[junit4] 2> 1698011 T5165 oasr.ManagedResourceStorage.newStorageIO Setting
up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1698011 T5165
oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured
ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1698012 T5165 oasr.RestManager.init Initializing RestManager
with initArgs: {}
[junit4] 2> 1698012 T5165 oasr.ManagedResourceStorage.load Reading
_rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1698013 T5165
oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found
for znode /configs/conf1/_rest_managed.json
[junit4] 2> 1698013 T5165 oasr.ManagedResourceStorage.load Loaded null at
path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1698013 T5165 oasr.RestManager.init Initializing 0 registered
ManagedResources
[junit4] 2> 1698014 T5165 oash.ReplicationHandler.inform Commits will be
reserved for 10000
[junit4] 2> 1698015 T5165 oasc.CoreContainer.registerCore registering
core: collection1
[junit4] 2> 1698015 T5166 oasc.SolrCore.registerSearcher [collection1]
Registered new searcher Searcher@2b95bec[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1698016 T5169 oasc.ZkController.register Register replica -
core:collection1 address:http://127.0.0.1:40753 collection:collection1
shard:shard1
[junit4] 2> 1698016 T5088 oass.SolrDispatchFilter.init
user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 1698017 T5088 oass.SolrDispatchFilter.init
SolrDispatchFilter.init() done
[junit4] 2> 1698017 T5169 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1698021 T5169 oasc.ShardLeaderElectionContext.runLeaderProcess
Running the leader process for shard shard1
[junit4] 2> 1698022 T5114 oasc.DistributedQueue$LatchWatcher.process
NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1698022 T5169
oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found
to continue.
[junit4] 2> 1698022 T5169 oasc.ShardLeaderElectionContext.runLeaderProcess
I may be the new leader - try and sync
[junit4] 2> 1698022 T5115 oasc.Overseer$ClusterStateUpdater.run
processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1"} current state version: 5
[junit4] 2> ASYNC NEW_CORE C1075 name=collection1
org.apache.solr.core.SolrCore@364e3f4a url=http://127.0.0.1:40753/collection1
node=127.0.0.1:40753_ C1075_STATE=coll:collection1 core:collection1
props:{core=collection1, base_url=http://127.0.0.1:40753,
node_name=127.0.0.1:40753_, state=down}
[junit4] 2> 1698022 T5169 C1075 P40753 oasc.SyncStrategy.sync Sync
replicas to http://127.0.0.1:40753/collection1/
[junit4] 2> 1698022 T5169 C1075 P40753 oasc.SyncStrategy.syncReplicas Sync
Success - now sync replicas to me
[junit4] 2> 1698023 T5169 C1075 P40753 oasc.SyncStrategy.syncToMe
http://127.0.0.1:40753/collection1/ has no replicas
[junit4] 2> 1698023 T5115 oasco.ZkStateWriter.writePendingUpdates going to
update_collection /collections/collection1/state.json version: 5
[junit4] 2> 1698023 T5169 oasc.ShardLeaderElectionContext.runLeaderProcess
I am the new leader: http://127.0.0.1:40753/collection1/ shard1
[junit4] 2> 1698023 T5169 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1698023 T5164 oascc.ZkStateReader$7.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1698023 T5144 oascc.ZkStateReader$7.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1698024 T5164 oascc.ZkStateReader.updateWatchedCollection
Updating data for collection1 to ver 6
[junit4] 2> 1698024 T5144 oascc.ZkStateReader.updateWatchedCollection
Updating data for collection1 to ver 6
[junit4] 2> 1698025 T5114 oasc.DistributedQueue$LatchWatcher.process
NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1698025 T5115 oasc.Overseer$ClusterStateUpdater.run
processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"http://127.0.0.1:40753";,
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"} current state version: 5
[junit4] 2> 1698026 T5115 oasco.ZkStateWriter.writePendingUpdates going to
update_collection /collections/collection1/state.json version: 6
[junit4] 2> 1698026 T5164 oascc.ZkStateReader$7.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1698026 T5144 oascc.ZkStateReader$7.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1698027 T5164 oascc.ZkStateReader.updateWatchedCollection
Updating data for collection1 to ver 7
[junit4] 2> 1698027 T5144 oascc.ZkStateReader.updateWatchedCollection
Updating data for collection1 to ver 7
[junit4] 2> 1698075 T5169 oasc.ZkController.register We are
http://127.0.0.1:40753/collection1/ and leader is
http://127.0.0.1:40753/collection1/
[junit4] 2> 1698076 T5169 oasc.ZkController.register No LogReplay needed
for core=collection1 baseURL=http://127.0.0.1:40753
[junit4] 2> 1698076 T5169 oasc.ZkController.checkRecovery I am the leader,
no recovery necessary
[junit4] 2> 1698076 T5169 oasc.ZkController.publish publishing
core=collection1 state=active collection=collection1
[junit4] 2> 1698076 T5169 oasc.ZkController.publish numShards not found on
descriptor - reading it from system property
[junit4] 2> 1698077 T5114 oasc.DistributedQueue$LatchWatcher.process
NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1698078 T5115 oasc.Overseer$ClusterStateUpdater.run
processMessage: queueSize: 1, message = {
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:40753";,
[junit4] 2> "node_name":"127.0.0.1:40753_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"} current state version: 5
[junit4] 2> 1698078 T5115 oasco.ReplicaMutator.updateState Update state
numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:40753";,
[junit4] 2> "node_name":"127.0.0.1:40753_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[ju
[...truncated too long message...]
$TransferStack.awaitFulfill(SynchronousQueue.java:460)
[junit4] 2> at
java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
[junit4] 2> at
java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
[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> 30) Thread[id=5134, name=qtp1105875591-5134 Acceptor1
[email protected]:59892, state=RUNNABLE,
group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at
org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:956)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 31) Thread[id=5167, name=Thread-2038, state=WAITING,
group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.lang.Object.wait(Object.java:502)
[junit4] 2> at
org.apache.solr.core.CloserThread.run(CoreContainer.java:929)
[junit4] 2> 32) Thread[id=5152, name=qtp735740999-5152 Selector1,
state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at
sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
[junit4] 2> at
sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
[junit4] 2> at
sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
[junit4] 2> at
sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
[junit4] 2> at
sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
[junit4] 2> at
org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
[junit4] 2> at
org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 33) Thread[id=5196,
name=commitScheduler-2638-thread-1, state=WAITING,
group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
[junit4] 2> at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
[junit4] 2> at
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081)
[junit4] 2> at
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 34) Thread[id=5809, name=zkCallback-692-thread-115,
state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] 2> at
java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
[junit4] 2> at
java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
[junit4] 2> at
java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
[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> NOTE: test params are:
codec=DummyCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=DUMMY,
chunkSize=10045, maxDocsPerChunk=815),
termVectorsFormat=CompressingTermVectorsFormat(compressionMode=DUMMY,
chunkSize=10045)), sim=RandomSimilarityProvider(queryNorm=true,coord=crazy):
{}, locale=iw_IL, timezone=Asia/Hong_Kong
[junit4] 2> NOTE: Linux 3.13.0-43-generic amd64/Oracle Corporation
1.9.0-ea (64-bit)/cpus=8,threads=40,free=191353176,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestExceedMaxTermLength,
URLClassifyProcessorTest, FacetPivotSmallTest,
HdfsCollectionsAPIDistributedZkTest, TestSolrConfigHandlerCloud,
SpellPossibilityIteratorTest, TestSolrDeletionPolicy1,
TriLevelCompositeIdRoutingTest, RollingRestartTest,
TestPHPSerializedResponseWriter, TestNonDefinedSimilarityFactory,
OverriddenZkACLAndCredentialsProvidersTest, JsonLoaderTest,
TestCollationFieldDocValues, TestLFUCache, DocumentBuilderTest,
SignatureUpdateProcessorFactoryTest, SpellCheckCollatorTest, TestRTGBase,
UpdateParamsTest, IndexBasedSpellCheckerTest, TestCharFilters, CopyFieldTest,
ExternalCollectionsTest, TestFieldResource, TestReplicationHandlerBackup,
TestFiltering, DistributedQueryComponentCustomSortTest,
TestDefaultSearchFieldResource, TestPostingsSolrHighlighter,
SchemaVersionSpecificBehaviorTest, ExternalFileFieldSortTest, BadCopyFieldTest,
TestInitQParser, TestSolrJ, IndexSchemaTest, CollectionsAPIDistributedZkTest,
TestSortingResponseWriter, TestFreeTextSuggestions, QueryEqualityTest,
ResponseLogComponentTest, PrimitiveFieldTypeTest, CSVRequestHandlerTest,
DebugComponentTest, TermVectorComponentDistributedTest, SolrCmdDistributorTest,
SampleTest, FileUtilsTest, ScriptEngineTest, TestDefaultStatsCache,
TestRawResponseWriter, TestJoin, ConnectionManagerTest, ShardSplitTest,
ModifyConfFileTest, TestZkChroot, TestStandardQParsers,
AsyncMigrateRouteKeyTest, TestConfig, TestJmxMonitoredMap,
WordBreakSolrSpellCheckerTest, RegexBoostProcessorTest,
FullSolrCloudDistribCmdsTest, TestFieldTypeResource, TestFastLRUCache,
QueryResultKeyTest, ShardRoutingCustomTest, TestMissingGroups,
AliasIntegrationTest, TestExactStatsCache, UUIDUpdateProcessorFallbackTest,
TestDynamicLoading, BasicDistributedZk2Test, TestIntervalFaceting,
AnalyticsMergeStrategyTest, HdfsUnloadDistributedZkTest, DateRangeFieldTest,
DisMaxRequestHandlerTest, BadComponentTest, ChaosMonkeyNothingIsSafeTest,
TestTolerantSearch, LeaderElectionIntegrationTest,
TestDefaultSimilarityFactory, ConvertedLegacyTest, TestDocSet, TestRecovery,
UpdateRequestProcessorFactoryTest, SimplePostToolTest, HdfsDirectoryTest,
SolrRequestParserTest, StatsComponentTest, FastVectorHighlighterTest,
TestSuggestSpellingConverter, TestSerializedLuceneMatchVersion,
TestRandomMergePolicy, TestAnalyzeInfixSuggestions, TestRealTimeGet,
TestAddFieldRealTimeGet, TestDynamicFieldResource, DocValuesMissingTest,
HdfsChaosMonkeySafeLeaderTest, SpatialFilterTest, CurrencyFieldXmlFileTest,
TestImplicitCoreProperties, TestCollectionAPI,
TestLMJelinekMercerSimilarityFactory, TestSchemaManager,
TestSchemaSimilarityResource, TestManagedSchemaFieldResource, TestTrie,
ChaosMonkeySafeLeaderTest]
[junit4] 2> NOTE: reproduce with: ant test
-Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=78D62EC33B461E33
-Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=iw_IL
-Dtests.timezone=Asia/Hong_Kong -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J1 | ChaosMonkeySafeLeaderTest (suite) <<<
[junit4] > Throwable #1: java.lang.Exception: Suite timeout exceeded (>=
7200000 msec).
[junit4] > at
__randomizedtesting.SeedInfo.seed([78D62EC33B461E33]:0)
[junit4] Completed on J1 in 7224.07s, 1 test, 2 errors <<< FAILURES!
[...truncated 11 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:519: The following
error occurred while executing this line:
/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:61: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:39: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:187: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:510:
The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1349:
The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:956:
There were test failures: 459 suites, 1856 tests, 1 suite-level error, 1 error,
32 ignored (22 assumptions)
Total time: 173 minutes 54 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.9.0-ea-b34
-XX:-UseCompressedOops -XX:+UseG1GC (asserts: true)
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
