You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/11/16 10:58:57 UTC
[JENKINS] Lucene-Solr-5.x-Linux (64bit/jdk1.8.0_20) - Build # 11458
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-5.x-Linux/11458/
Java: 64bit/jdk1.8.0_20 -XX:-UseCompressedOops -XX:+UseSerialGC (asserts: false)
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([73662F24FBB35E76]:0)
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
Test abandoned because suite timeout was reached.
Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
at __randomizedtesting.SeedInfo.seed([73662F24FBB35E76]:0)
Build Log:
[...truncated 12550 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/init-core-data-001
[junit4] 2> 1526925 T4208 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
[junit4] 2> 1526925 T4208 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 1526928 T4208 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 1526929 T4208 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1526929 T4209 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1527029 T4208 oasc.ZkTestServer.run start zk server on port:44628
[junit4] 2> 1527030 T4208 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 1527030 T4208 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1527033 T4215 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13b9cc26 name:ZooKeeperConnection Watcher:127.0.0.1:44628 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1527033 T4208 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1527033 T4208 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 1527034 T4208 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1527036 T4208 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 1527037 T4208 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1527038 T4217 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45aa9ea5 name:ZooKeeperConnection Watcher:127.0.0.1:44628/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1527038 T4208 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1527038 T4208 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 1527039 T4208 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1527040 T4208 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1527042 T4208 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1527043 T4208 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1527044 T4208 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1527044 T4208 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1527045 T4208 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 1527046 T4208 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1527047 T4208 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1527048 T4208 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1527049 T4208 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1527049 T4208 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1527050 T4208 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1527051 T4208 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1527052 T4208 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1527052 T4208 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1527053 T4208 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1527053 T4208 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 1527055 T4208 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1527055 T4208 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1527056 T4208 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1527057 T4208 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1527058 T4208 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1527058 T4208 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1527060 T4208 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1527060 T4208 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1527061 T4208 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 1527062 T4208 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1527063 T4219 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e00ced6 name:ZooKeeperConnection Watcher:127.0.0.1:44628/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1527064 T4208 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1527064 T4208 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 1527321 T4208 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1527324 T4208 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 1527328 T4208 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:40043
[junit4] 2> 1527329 T4208 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1527330 T4208 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1527330 T4208 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-002
[junit4] 2> 1527331 T4208 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-002/'
[junit4] 2> 1527348 T4208 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-002/solr.xml
[junit4] 2> 1527360 T4208 oasc.CoreContainer.<init> New CoreContainer 1094559978
[junit4] 2> 1527360 T4208 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-002/]
[junit4] 2> 1527361 T4208 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1527361 T4208 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1527362 T4208 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1527362 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1527362 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
[junit4] 2> 1527363 T4208 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1527363 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1527363 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1527364 T4208 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1527364 T4208 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1527366 T4208 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 1527367 T4208 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1527367 T4208 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1527367 T4208 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1527368 T4208 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44628/solr
[junit4] 2> 1527368 T4208 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1527369 T4208 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 1527560 T4208 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1527562 T4230 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b316ac0 name:ZooKeeperConnection Watcher:127.0.0.1:44628 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1527562 T4208 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1527563 T4208 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 1527565 T4208 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1527566 T4232 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7768736b name:ZooKeeperConnection Watcher:127.0.0.1:44628/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1527566 T4208 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1527567 T4208 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1527569 T4208 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1527570 T4208 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1527572 T4208 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1527573 T4208 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1527574 T4208 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1527575 T4208 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40043_
[junit4] 2> 1527576 T4208 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40043_
[junit4] 2> 1527577 T4208 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1527578 T4208 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1527579 T4208 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1527580 T4208 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:40043_
[junit4] 2> 1527580 T4208 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1527581 T4208 oasc.Overseer.start Overseer (id=92807147445354500-127.0.0.1:40043_-n_0000000000) starting
[junit4] 2> 1527582 T4208 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1527586 T4208 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1527586 T4234 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1527587 T4208 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1527589 T4208 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1527590 T4208 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1527592 T4233 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1527593 T4236 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 1527593 T4236 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1527594 T4236 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1527594 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1527595 T4233 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:40043",
[junit4] 2> "node_name":"127.0.0.1:40043_",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 1527595 T4233 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1527595 T4233 oasc.Overseer$ClusterStateUpdater.createCollection state version control_collection 1
[junit4] 2> 1527595 T4233 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1527596 T4237 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> 1528594 T4236 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1528594 T4236 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1528595 T4236 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1528595 T4236 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1528595 T4236 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1528596 T4236 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-002/collection1/'
[junit4] 2> 1528596 T4236 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 1528596 T4236 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 1528597 T4236 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 1528615 T4236 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 1528634 T4236 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1528635 T4236 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
[junit4] 2> 1528638 T4236 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1528729 T4236 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1528730 T4236 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1528731 T4236 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1528734 T4236 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1528745 T4236 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 1528745 T4236 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 1528746 T4236 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-002/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/control/data/
[junit4] 2> 1528746 T4236 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4caf0ee3
[junit4] 2> 1528747 T4236 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/control/data
[junit4] 2> 1528748 T4236 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/control/data/index/
[junit4] 2> 1528748 T4236 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1528749 T4236 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/control/data/index
[junit4] 2> 1528749 T4236 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=37, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1528934 T4236 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 1528934 T4236 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1528936 T4236 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1528936 T4236 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1528936 T4236 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1528936 T4236 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1528937 T4236 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1528937 T4236 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1528937 T4236 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1528937 T4236 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1528937 T4236 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1528938 T4236 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1528938 T4236 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1528938 T4236 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1528938 T4236 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1528939 T4236 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1528939 T4236 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1528939 T4236 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1528939 T4236 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1528939 T4236 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1528940 T4236 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1528940 T4236 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 1528941 T4236 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1528942 T4236 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1528942 T4236 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1528943 T4236 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1528944 T4236 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1528944 T4236 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1528945 T4236 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=38, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7467729801982084]
[junit4] 2> 1528945 T4236 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 1528945 T4236 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1528946 T4236 oass.SolrIndexSearcher.<init> Opening Searcher@52d21347[collection1] main
[junit4] 2> 1528946 T4236 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1528947 T4236 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1528947 T4236 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1528947 T4236 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1528947 T4236 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1528947 T4236 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1528948 T4236 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 1528948 T4236 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1528948 T4236 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json
[junit4] 2> 1528950 T4236 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json
[junit4] 2> 1528950 T4236 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1528950 T4236 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1528952 T4238 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@52d21347[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1528953 T4236 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1528953 T4241 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:40043 collection:control_collection shard:shard1
[junit4] 2> 1528954 T4208 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 1528954 T4208 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1528954 T4241 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1528956 T4208 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 1528957 T4208 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1528958 T4241 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1528958 T4243 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b120b2d name:ZooKeeperConnection Watcher:127.0.0.1:44628/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1528958 T4208 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1528959 T4208 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 1528959 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1528959 T4241 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1528960 T4241 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1181 name=collection1 org.apache.solr.core.SolrCore@f5f4a64 url=https://127.0.0.1:40043/collection1 node=127.0.0.1:40043_ C1181_STATE=coll:control_collection core:collection1 props:{core=collection1, base_url=https://127.0.0.1:40043, node_name=127.0.0.1:40043_, state=down}
[junit4] 2> 1528960 T4241 C1181 P40043 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:40043/collection1/
[junit4] 2> 1528960 T4241 C1181 P40043 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1528960 T4241 C1181 P40043 oasc.SyncStrategy.syncToMe https://127.0.0.1:40043/collection1/ has no replicas
[junit4] 2> 1528960 T4241 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:40043/collection1/ shard1
[junit4] 2> 1528961 T4241 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1528962 T4208 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1528964 T4208 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1528964 T4208 oasc.AbstractFullDistribZkTestBase.createJettys Creating collection1 with stateFormat=2
[junit4] 2> 1528964 T4208 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 1528965 T4208 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1528966 T4245 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d6e92d0 name:ZooKeeperConnection Watcher:127.0.0.1:44628/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1528966 T4208 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1528966 T4208 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 1528968 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1528969 T4233 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: collection1
[junit4] 2> 1528969 T4233 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1528969 T4233 oasc.Overseer$ClusterStateUpdater.createCollection state version collection1 2
[junit4] 2> 1528970 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1528971 T4233 oasc.Overseer$ClusterStateUpdater.updateZkStates going to create_collection /collections/collection1/state.json
[junit4] 2> 1528972 T4237 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> 1528972 T4246 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> 1529015 T4241 oasc.ZkController.register We are https://127.0.0.1:40043/collection1/ and leader is https://127.0.0.1:40043/collection1/
[junit4] 2> 1529016 T4241 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:40043
[junit4] 2> 1529016 T4241 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1529016 T4241 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 1529016 T4241 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1529017 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1529020 T4233 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:40043",
[junit4] 2> "node_name":"127.0.0.1:40043_",
[junit4] 2> "numShards":"3",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 1529124 T4246 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> 1529128 T4237 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> 1529229 T4208 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 1529230 T4208 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1529232 T4208 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 1529233 T4208 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:33858
[junit4] 2> 1529235 T4208 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1529235 T4208 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1529235 T4208 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-003
[junit4] 2> 1529235 T4208 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-003/'
[junit4] 2> 1529258 T4208 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-003/solr.xml
[junit4] 2> 1529266 T4208 oasc.CoreContainer.<init> New CoreContainer 1940143561
[junit4] 2> 1529267 T4208 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-003/]
[junit4] 2> 1529267 T4208 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1529267 T4208 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1529268 T4208 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1529268 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1529268 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
[junit4] 2> 1529268 T4208 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1529269 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1529269 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1529269 T4208 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1529269 T4208 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1529270 T4208 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 1529271 T4208 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1529271 T4208 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1529271 T4208 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1529272 T4208 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44628/solr
[junit4] 2> 1529272 T4208 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1529272 T4208 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 1529273 T4208 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1529275 T4257 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1efba9d0 name:ZooKeeperConnection Watcher:127.0.0.1:44628 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1529275 T4208 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1529276 T4208 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 1529278 T4208 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1529281 T4259 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e19c81c name:ZooKeeperConnection Watcher:127.0.0.1:44628/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1529281 T4208 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1529286 T4208 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1530289 T4208 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33858_
[junit4] 2> 1530290 T4208 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33858_
[junit4] 2> 1530293 T4208 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1530297 T4261 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 1530297 T4261 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1530298 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1530298 T4261 oasc.ZkController.preRegister Registering watch for external collection collection1
[junit4] 2> 1530299 T4261 oascc.ZkStateReader.addZkWatch addZkWatch collection1
[junit4] 2> 1530299 T4261 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper...
[junit4] 2> 1530300 T4261 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 0
[junit4] 2> 1530300 T4261 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1530302 T4233 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:33858",
[junit4] 2> "node_name":"127.0.0.1:33858_",
[junit4] 2> "numShards":"3",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 1530303 T4233 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1530304 T4233 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1530306 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1530307 T4233 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json
[junit4] 2> 1530307 T4260 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1530307 T4260 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 1
[junit4] 2> 1531300 T4261 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1531301 T4261 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1531301 T4261 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1531302 T4261 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1531303 T4261 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1531303 T4261 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-003/collection1/'
[junit4] 2> 1531304 T4261 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 1531305 T4261 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 1531305 T4261 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 1531333 T4261 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 1531345 T4261 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1531346 T4261 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
[junit4] 2> 1531350 T4261 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1531465 T4261 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1531466 T4261 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1531467 T4261 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1531469 T4261 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1531484 T4261 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 1531484 T4261 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 1531485 T4261 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-003/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/jetty1/
[junit4] 2> 1531485 T4261 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4caf0ee3
[junit4] 2> 1531486 T4261 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/jetty1
[junit4] 2> 1531486 T4261 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/jetty1/index/
[junit4] 2> 1531487 T4261 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1531488 T4261 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/jetty1/index
[junit4] 2> 1531489 T4261 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=37, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1531496 T4261 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 1531496 T4261 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1531499 T4261 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1531500 T4261 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1531500 T4261 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1531500 T4261 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1531500 T4261 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1531500 T4261 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1531501 T4261 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1531501 T4261 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1531501 T4261 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1531502 T4261 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1531502 T4261 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1531502 T4261 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1531503 T4261 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1531503 T4261 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1531503 T4261 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1531503 T4261 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1531504 T4261 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1531504 T4261 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1531504 T4261 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1531505 T4261 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 1531506 T4261 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1531507 T4261 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1531507 T4261 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1531508 T4261 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1531509 T4261 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1531509 T4261 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1531511 T4261 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=38, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7467729801982084]
[junit4] 2> 1531511 T4261 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 1531511 T4261 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1531512 T4261 oass.SolrIndexSearcher.<init> Opening Searcher@479c895c[collection1] main
[junit4] 2> 1531512 T4261 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1531513 T4261 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1531513 T4261 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1531513 T4261 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1531514 T4261 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1531514 T4261 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1531515 T4261 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
[junit4] 2> 1531515 T4261 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1531515 T4261 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
[junit4] 2> 1531515 T4261 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1531517 T4262 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@479c895c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1531518 T4261 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1531518 T4265 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:33858 collection:collection1 shard:shard2
[junit4] 2> 1531519 T4208 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 1531519 T4208 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1531519 T4265 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1531522 T4265 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1531523 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1531524 T4265 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1531524 T4265 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1182 name=collection1 org.apache.solr.core.SolrCore@61ea3f75 url=https://127.0.0.1:33858/collection1 node=127.0.0.1:33858_ C1182_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=https://127.0.0.1:33858, node_name=127.0.0.1:33858_, state=down}
[junit4] 2> 1531524 T4265 C1182 P33858 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:33858/collection1/
[junit4] 2> 1531524 T4265 C1182 P33858 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1531525 T4265 C1182 P33858 oasc.SyncStrategy.syncToMe https://127.0.0.1:33858/collection1/ has no replicas
[junit4] 2> 1531525 T4265 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:33858/collection1/ shard2
[junit4] 2> 1531525 T4265 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1531527 T4233 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json
[junit4] 2> 1531528 T4260 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1531529 T4260 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 2
[junit4] 2> 1531533 T4233 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json
[junit4] 2> 1531533 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1531533 T4260 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1531534 T4260 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 3
[junit4] 2> 1531581 T4265 oasc.ZkController.register We are https://127.0.0.1:33858/collection1/ and leader is https://127.0.0.1:33858/collection1/
[junit4] 2> 1531581 T4265 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:33858
[junit4] 2> 1531581 T4265 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1531581 T4265 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 1531581 T4265 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1531582 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1531584 T4265 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 3
[junit4] 2> 1531585 T4233 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:33858",
[junit4] 2> "node_name":"127.0.0.1:33858_",
[junit4] 2> "numShards":"3",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 1531588 T4233 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json
[junit4] 2> 1531588 T4260 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1531589 T4260 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4
[junit4] 2> 1531761 T4208 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 1531762 T4208 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1531764 T4208 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 1531765 T4208 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:52519
[junit4] 2> 1531767 T4208 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1531767 T4208 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1531768 T4208 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-004
[junit4] 2> 1531768 T4208 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-004/'
[junit4] 2> 1531778 T4208 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-004/solr.xml
[junit4] 2> 1531786 T4208 oasc.CoreContainer.<init> New CoreContainer 827312593
[junit4] 2> 1531786 T4208 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-004/]
[junit4] 2> 1531787 T4208 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1531787 T4208 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1531787 T4208 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1531787 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1531788 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
[junit4] 2> 1531788 T4208 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1531788 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1531788 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1531789 T4208 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1531789 T4208 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1531790 T4208 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 1531790 T4208 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1531791 T4208 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1531791 T4208 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1531791 T4208 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44628/solr
[junit4] 2> 1531791 T4208 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1531792 T4208 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 1531792 T4208 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1531794 T4276 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@615e10d1 name:ZooKeeperConnection Watcher:127.0.0.1:44628 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1531795 T4208 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1531795 T4208 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 1531798 T4208 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1531799 T4278 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e6a20ae name:ZooKeeperConnection Watcher:127.0.0.1:44628/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1531800 T4208 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1531804 T4208 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1532806 T4208 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52519_
[junit4] 2> 1532807 T4208 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52519_
[junit4] 2> 1532810 T4208 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1532814 T4280 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 1532814 T4280 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1532815 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1532815 T4280 oasc.ZkController.preRegister Registering watch for external collection collection1
[junit4] 2> 1532815 T4280 oascc.ZkStateReader.addZkWatch addZkWatch collection1
[junit4] 2> 1532816 T4280 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper...
[junit4] 2> 1532817 T4280 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4
[junit4] 2> 1532817 T4280 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1532817 T4233 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:52519",
[junit4] 2> "node_name":"127.0.0.1:52519_",
[junit4] 2> "numShards":"3",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 1532818 T4233 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1532819 T4233 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 1532821 T4233 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json
[junit4] 2> 1532821 T4260 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1532821 T4279 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1532821 T4260 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5
[junit4] 2> 1532822 T4279 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5
[junit4] 2> 1533817 T4280 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1533817 T4280 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1533818 T4280 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1533818 T4280 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1533819 T4280 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1533819 T4280 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-004/collection1/'
[junit4] 2> 1533819 T4280 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 1533820 T4280 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 1533820 T4280 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 1533837 T4280 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 1533859 T4280 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1533860 T4280 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
[junit4] 2> 1533863 T4280 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1533946 T4280 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1533947 T4280 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1533948 T4280 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1533951 T4280 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1533960 T4280 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 1533961 T4280 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 1533961 T4280 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-004/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/jetty2/
[junit4] 2> 1533961 T4280 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4caf0ee3
[junit4] 2> 1533962 T4280 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/jetty2
[junit4] 2> 1533962 T4280 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/jetty2/index/
[junit4] 2> 1533962 T4280 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1533963 T4280 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/jetty2/index
[junit4] 2> 1533964 T4280 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=37, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1533969 T4280 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 1533970 T4280 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1533972 T4280 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1533972 T4280 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1533972 T4280 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1533972 T4280 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1533973 T4280 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1533973 T4280 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1533973 T4280 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1533973 T4280 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1533973 T4280 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1533974 T4280 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1533974 T4280 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1533974 T4280 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 1533974 T4280 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1533975 T4280 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1533975 T4280 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1533975 T4280 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1533975 T4280 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1533975 T4280 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1533976 T4280 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1533976 T4280 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 1533977 T4280 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1533978 T4280 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1533979 T4280 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1533979 T4280 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1533980 T4280 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1533981 T4280 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1533982 T4280 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=38, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7467729801982084]
[junit4] 2> 1533982 T4280 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 1533983 T4280 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1533983 T4280 oass.SolrIndexSearcher.<init> Opening Searcher@7d4ee21d[collection1] main
[junit4] 2> 1533983 T4280 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1533984 T4280 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1533984 T4280 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1533984 T4280 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1533985 T4280 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1533985 T4280 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1533985 T4280 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
[junit4] 2> 1533986 T4280 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1533986 T4280 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
[junit4] 2> 1533986 T4280 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1533987 T4281 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7d4ee21d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1533989 T4280 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1533989 T4284 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:52519 collection:collection1 shard:shard3
[junit4] 2> 1533990 T4208 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 1533990 T4284 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 1533990 T4208 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1533993 T4284 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
[junit4] 2> 1533993 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1533994 T4284 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1533994 T4284 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1183 name=collection1 org.apache.solr.core.SolrCore@283e0c8e url=https://127.0.0.1:52519/collection1 node=127.0.0.1:52519_ C1183_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=https://127.0.0.1:52519, node_name=127.0.0.1:52519_, state=down}
[junit4] 2> 1533994 T4284 C1183 P52519 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:52519/collection1/
[junit4] 2> 1533995 T4284 C1183 P52519 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1533995 T4284 C1183 P52519 oasc.SyncStrategy.syncToMe https://127.0.0.1:52519/collection1/ has no replicas
[junit4] 2> 1533995 T4284 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:52519/collection1/ shard3
[junit4] 2> 1533996 T4284 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 1533997 T4233 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json
[junit4] 2> 1533997 T4279 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1533997 T4260 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1533998 T4279 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 6
[junit4] 2> 1533998 T4260 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 6
[junit4] 2> 1534001 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1534001 T4233 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json
[junit4] 2> 1534002 T4279 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1534002 T4260 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1534002 T4260 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 7
[junit4] 2> 1534004 T4279 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 7
[junit4] 2> 1534049 T4284 oasc.ZkController.register We are https://127.0.0.1:52519/collection1/ and leader is https://127.0.0.1:52519/collection1/
[junit4] 2> 1534049 T4284 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:52519
[junit4] 2> 1534049 T4284 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1534049 T4284 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 1534050 T4284 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1534050 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1534052 T4233 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:52519",
[junit4] 2> "node_name":"127.0.0.1:52519_",
[junit4] 2> "numShards":"3",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 1534053 T4284 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 7
[junit4] 2> 1534055 T4233 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json
[junit4] 2> 1534056 T4279 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1534056 T4260 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1534056 T4279 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 8
[junit4] 2> 1534056 T4260 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 8
[junit4] 2> 1534245 T4208 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 1534246 T4208 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1534248 T4208 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 1534249 T4208 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:54686
[junit4] 2> 1534251 T4208 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1534251 T4208 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1534251 T4208 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-005
[junit4] 2> 1534252 T4208 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-005/'
[junit4] 2> 1534263 T4208 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-005/solr.xml
[junit4] 2> 1534271 T4208 oasc.CoreContainer.<init> New CoreContainer 150131732
[junit4] 2> 1534271 T4208 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73662F24FBB35E76-001/tempDir-005/]
[junit4] 2> 1534271 T4208 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1534272 T4208 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1534272 T4208 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1534272 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1534272 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
[junit4] 2> 1534273 T4208 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1534273 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1534273 T4208 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1534273 T4208 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1534273 T4208 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1534274 T4208 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 1534275 T4208 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1534275 T4208 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1534276 T4208 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1534276 T4208 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44628/solr
[junit4] 2> 1534276 T4208 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1534276 T4208 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 1534277 T4208 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1534279 T4295 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e130bf8 name:ZooKeeperConnection Watcher:127.0.0.1:44628 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1534280 T4208 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1534280 T4208 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 1534282 T4208 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1534285 T4297 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d9293ee name:ZooKeeperConnection Watcher:127.0.0.1:44628/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1534286 T4208 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1534289 T4208 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1535292 T4208 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54686_
[junit4] 2> 1535293 T4208 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54686_
[junit4] 2> 1535296 T4208 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1535299 T4299 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 1535300 T4299 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1535301 T4237 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 1535301 T4299 oasc.ZkController.preRegister Registering watch for external collection collection1
[junit4] 2> 1535301 T4299 oascc.ZkStateReader.addZkWatch addZkWatch collection1
[junit4] 2> 1535301 T4299 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper...
[junit4] 2> 1535302 T4299 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 8
[junit4] 2> 1535302 T4233 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:54686",
[junit4] 2> "node_name":"127.0.0.1:54686_",
[junit4] 2> "numShards":"3",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 1535302 T4299 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1535304 T4233 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1535304 T4233 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1535306 T4233 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json
[junit4] 2> 1535307 T4279 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1535307 T4260 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating...
[junit4] 2> 1535307 T4298 oascc.ZkStateReader$7.process A cl
[...truncated too long message...]
hreadPoolExecutor.java:617)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 41) Thread[id=4250, name=qtp1389284093-4250 Acceptor0 SslSelectChannelConnector@127.0.0.1:33858, state=BLOCKED, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at org.eclipse.jetty.server.nio.SelectChannelConnector.getConnection(SelectChannelConnector.java:160)
[junit4] 2> at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:934)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 42) Thread[id=4306, name=qtp915342003-4306 Selector1, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.nio.ch.EPollArrayWrapper.interrupt(Native Method)
[junit4] 2> at sun.nio.ch.EPollArrayWrapper.interrupt(EPollArrayWrapper.java:317)
[junit4] 2> at sun.nio.ch.EPollSelectorImpl.wakeup(EPollSelectorImpl.java:193)
[junit4] 2> at java.nio.channels.spi.AbstractSelector$1.interrupt(AbstractSelector.java:213)
[junit4] 2> at java.nio.channels.spi.AbstractSelector.begin(AbstractSelector.java:219)
[junit4] 2> at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:78)
[junit4] 2> at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
[junit4] 2> at sun.nio.ch.SelectorImpl.selectNow(SelectorImpl.java:105)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:536)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 43) Thread[id=4249, name=qtp1389284093-4249 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> 44) Thread[id=4267, name=qtp802304712-4267 Selector0, 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> 45) Thread[id=4270, name=qtp802304712-4270 Acceptor1 SslSelectChannelConnector@127.0.0.1:52519, 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> NOTE: test params are: codec=Asserting(Lucene50): {rnd_b=FSTOrd50, _version_=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), a_t=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), a_i=FSTOrd50, id=FSTOrd50}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=sk, timezone=ROK
[junit4] 2> NOTE: Linux 3.13.0-39-generic amd64/Oracle Corporation 1.8.0_20 (64-bit)/cpus=8,threads=54,free=151576624,total=435236864
[junit4] 2> NOTE: All tests run in this JVM: [DistribDocExpirationUpdateProcessorTest, PrimUtilsTest, ClusterStateTest, CSVRequestHandlerTest, TestAddFieldRealTimeGet, TestCollapseQParserPlugin, TestCharFilters, TestSolrXmlPersistence, SharedFSAutoReplicaFailoverTest, DebugComponentTest, SynonymTokenizerTest, CurrencyFieldXmlFileTest, AnalysisErrorHandlingTest, TestAtomicUpdateErrorCases, TestReversedWildcardFilterFactory, HdfsCollectionsAPIDistributedZkTest, ScriptEngineTest, TestSolrQueryParser, MultiThreadedOCPTest, TestExtendedDismaxParser, TestSerializedLuceneMatchVersion, PolyFieldTest, LegacyHTMLStripCharFilterTest, RequestHandlersTest, DistributedFacetPivotSmallAdvancedTest, CollectionsAPIAsyncDistributedZkTest, SolrInfoMBeanTest, DefaultValueUpdateProcessorTest, SoftAutoCommitTest, TestSortingResponseWriter, TestCSVResponseWriter, PreAnalyzedFieldTest, DateMathParserTest, TestCloudInspectUtil, ResourceLoaderTest, SimplePostToolTest, DirectUpdateHandlerOptimizeTest, AliasIntegrationTest, TestSolrXmlPersistor, LoggingHandlerTest, DistributedQueryComponentOptimizationTest, TestLazyCores, TestManagedResourceStorage, ShardSplitTest, CopyFieldTest, TestDistribDocBasedVersion, ShardRoutingCustomTest, TestWriterPerf, DirectSolrConnectionTest, SearchHandlerTest, LeaderElectionIntegrationTest, HdfsLockFactoryTest, AddBlockUpdateTest, CoreMergeIndexesAdminHandlerTest, HardAutoCommitTest, TermVectorComponentDistributedTest, BasicZkTest, TestJoin, TestOmitPositions, TestCSVLoader, SpatialFilterTest, DistributedFacetPivotLongTailTest, TestZkChroot, SortByFunctionTest, TestPivotHelperCode, TestValueSourceCache, TestQuerySenderNoQuery, BinaryUpdateRequestHandlerTest, TestLFUCache, ZkSolrClientTest, TestQueryTypes, AnalysisAfterCoreReloadTest, TestCoreContainer, TestBulkSchemaConcurrent, CacheHeaderTest, AsyncMigrateRouteKeyTest, CoreContainerCoreInitFailuresTest, SSLMigrationTest, SolrPluginUtilsTest, LukeRequestHandlerTest, TestDynamicFieldResource, TestSchemaNameResource, TestFieldTypeCollectionResource, DistanceFunctionTest, TestOrdValues, AutoCommitTest, BasicDistributedZk2Test, TestBadConfig, CircularListTest, CursorPagingTest, TestStandardQParsers, TestCollectionAPI, SolrCoreTest, SuggesterFSTTest, QueryElevationComponentTest, URLClassifyProcessorTest, TestSweetSpotSimilarityFactory, TestSolrQueryParserDefaultOperatorResource, TestDistributedGrouping, TestFunctionQuery, ChangedSchemaMergeTest, DeleteInactiveReplicaTest, RAMDirectoryFactoryTest, TestCustomSort, DistributedTermsComponentTest, TestInitParams, ChaosMonkeySafeLeaderTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=73662F24FBB35E76 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sk -Dtests.timezone=ROK -Dtests.asserts=false -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([73662F24FBB35E76]:0)
[junit4] Completed on J1 in 7224.29s, 1 test, 2 errors <<< FAILURES!
[...truncated 11 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:525: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:473: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:61: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/extra-targets.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/common-build.xml:508: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/lucene/common-build.xml:1359: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/lucene/common-build.xml:966: There were test failures: 444 suites, 1818 tests, 1 suite-level error, 1 error, 29 ignored (21 assumptions)
Total time: 193 minutes 2 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0_20 -XX:-UseCompressedOops -XX:+UseSerialGC (asserts: false)
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any