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