You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/09/18 22:07:16 UTC
[JENKINS] Lucene-Solr-5.x-Linux (32bit/jdk1.9.0-ea-b28) - Build #
11133 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-5.x-Linux/11133/
Java: 32bit/jdk1.9.0-ea-b28 -server -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.BasicDistributedZkTest.testDistribSearch
Error Message:
commitWithin did not work on node: http://127.0.0.1:55405/gb_k/collection1 expected:<68> but was:<67>
Stack Trace:
java.lang.AssertionError: commitWithin did not work on node: http://127.0.0.1:55405/gb_k/collection1 expected:<68> but was:<67>
at __randomizedtesting.SeedInfo.seed([F7A2FC7A28D904D9:764472625F8664E5]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.BasicDistributedZkTest.doTest(BasicDistributedZkTest.java:355)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:871)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:484)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 10890 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/init-core-data-001
[junit4] 2> 111091 T299 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /gb_k/
[junit4] 2> 111095 T299 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 111095 T299 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 111096 T300 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 111196 T299 oasc.ZkTestServer.run start zk server on port:43639
[junit4] 2> 111197 T299 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 111197 T299 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 111200 T306 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@173f6fc name:ZooKeeperConnection Watcher:127.0.0.1:43639 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 111200 T299 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 111201 T299 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 111201 T299 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 111203 T299 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 111204 T299 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 111205 T308 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e018f5 name:ZooKeeperConnection Watcher:127.0.0.1:43639/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 111205 T299 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 111206 T299 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 111206 T299 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 111208 T299 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 111209 T299 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 111210 T299 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 111211 T299 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 111211 T299 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 111213 T299 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 111213 T299 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 111215 T299 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 111215 T299 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 111217 T299 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 111217 T299 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 111219 T299 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 111219 T299 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 111220 T299 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 111221 T299 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 111222 T299 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 111223 T299 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 111224 T299 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 111224 T299 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 111226 T299 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 111226 T299 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 111227 T299 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 111228 T299 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 111229 T299 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 111229 T299 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 111471 T299 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 111475 T299 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57054
[junit4] 2> 111475 T299 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 111475 T299 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 111476 T299 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-002
[junit4] 2> 111476 T299 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-002/'
[junit4] 2> 111487 T299 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-002/solr.xml
[junit4] 2> 111502 T299 oasc.CoreContainer.<init> New CoreContainer 18522497
[junit4] 2> 111502 T299 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-002/]
[junit4] 2> 111503 T299 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 111503 T299 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 111504 T299 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 111504 T299 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 111504 T299 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 111505 T299 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 111505 T299 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 111506 T299 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 111506 T299 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 111507 T299 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 111507 T299 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 111508 T299 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 111508 T299 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 111508 T299 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43639/solr
[junit4] 2> 111509 T299 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 111509 T299 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 111510 T299 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 111512 T319 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b6997 name:ZooKeeperConnection Watcher:127.0.0.1:43639 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 111514 T299 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 111515 T299 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 111521 T299 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 111522 T321 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c7adfd name:ZooKeeperConnection Watcher:127.0.0.1:43639/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 111522 T299 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 111523 T299 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 111525 T299 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 111527 T299 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 111528 T299 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 111530 T299 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 111532 T299 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 111533 T299 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57054_gb_k
[junit4] 2> 111534 T299 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57054_gb_k
[junit4] 2> 111535 T299 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 111537 T299 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 111539 T299 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 111540 T299 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57054_gb_k
[junit4] 2> 111541 T299 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 111542 T299 oasc.Overseer.start Overseer (id=92475766644080643-127.0.0.1:57054_gb_k-n_0000000000) starting
[junit4] 2> 111549 T299 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 111554 T299 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 111554 T323 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 111555 T299 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 111557 T299 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 111558 T299 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 111560 T322 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 111563 T325 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 111563 T325 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 111565 T325 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 111565 T326 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 111571 T322 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:57054/gb_k",
[junit4] 2> "node_name":"127.0.0.1:57054_gb_k",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 111571 T322 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 111574 T322 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 111577 T326 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> 112566 T325 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 112566 T325 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 112567 T325 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 112567 T325 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 112568 T325 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 112568 T325 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-002/collection1/'
[junit4] 2> 112569 T325 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 112569 T325 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 112569 T325 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 112600 T325 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 112609 T325 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 112611 T325 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 112615 T325 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 112738 T325 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 112739 T325 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 112739 T325 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 112743 T325 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 112744 T325 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 112754 T325 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 112756 T325 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 112758 T325 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 112759 T325 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 112759 T325 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 112759 T325 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 112760 T325 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 112760 T325 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 112760 T325 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 112760 T325 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 112760 T325 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-002/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/control/data/
[junit4] 2> 112761 T325 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@8564dd
[junit4] 2> 112761 T325 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/control/data
[junit4] 2> 112761 T325 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/control/data/index/
[junit4] 2> 112762 T325 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 112762 T325 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/control/data/index
[junit4] 2> 112762 T325 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=42, maxMergedSegmentMB=84.595703125, floorSegmentMB=1.4208984375, forceMergeDeletesPctAllowed=29.309084928402118, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 112763 T325 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1c967c6)),segFN=segments_1,generation=1}
[junit4] 2> 112763 T325 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 112766 T325 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 112777 T325 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 112777 T325 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 112778 T325 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 112778 T325 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 112778 T325 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 112778 T325 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 112778 T325 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 112779 T325 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 112779 T325 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 112780 T325 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 112780 T325 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 112780 T325 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 112781 T325 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 112781 T325 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 112781 T325 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 112781 T325 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 112782 T325 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 112782 T325 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 112783 T325 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 112790 T325 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 112791 T325 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 112792 T325 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 112793 T325 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 112793 T325 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 112794 T325 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=35, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=34.8740234375, floorSegmentMB=1.4296875, forceMergeDeletesPctAllowed=9.470844257815504, segmentsPerTier=32.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 112794 T325 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1c967c6)),segFN=segments_1,generation=1}
[junit4] 2> 112794 T325 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 112795 T325 oass.SolrIndexSearcher.<init> Opening Searcher@66408a[collection1] main
[junit4] 2> 112795 T325 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 112796 T325 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 112796 T325 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 112798 T325 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 112798 T325 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 112798 T325 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 112799 T325 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 112799 T325 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 112800 T325 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json
[junit4] 2> 112801 T325 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json
[junit4] 2> 112801 T325 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 112801 T325 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 112804 T327 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@66408a[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 112805 T325 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 112806 T330 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57054/gb_k collection:control_collection shard:shard1
[junit4] 2> 112806 T299 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 112807 T299 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 112816 T299 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 112817 T330 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 112817 T299 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 112819 T332 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c892f9 name:ZooKeeperConnection Watcher:127.0.0.1:43639/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 112819 T299 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 112820 T299 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 112822 T299 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 112822 T330 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 112824 T326 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 112824 T330 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 112825 T330 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C52 name=collection1 org.apache.solr.core.SolrCore@17aaf80 url=http://127.0.0.1:57054/gb_k/collection1 node=127.0.0.1:57054_gb_k C52_STATE=coll:control_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:57054/gb_k, node_name=127.0.0.1:57054_gb_k, state=down}
[junit4] 2> 112825 T330 C52 P57054 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57054/gb_k/collection1/
[junit4] 2> 112826 T330 C52 P57054 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 112826 T330 C52 P57054 oasc.SyncStrategy.syncToMe http://127.0.0.1:57054/gb_k/collection1/ has no replicas
[junit4] 2> 112827 T299 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 112827 T330 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57054/gb_k/collection1/ shard1
[junit4] 2> 112829 T330 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 112833 T326 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 112937 T326 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> 112938 T333 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> 112985 T330 oasc.ZkController.register We are http://127.0.0.1:57054/gb_k/collection1/ and leader is http://127.0.0.1:57054/gb_k/collection1/
[junit4] 2> 112985 T330 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57054/gb_k
[junit4] 2> 112985 T330 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 112985 T330 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 112985 T330 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 112987 T326 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 112988 T322 oasc.Overseer$ClusterStateUpdater.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:57054/gb_k",
[junit4] 2> "node_name":"127.0.0.1:57054_gb_k",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 113091 T333 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> 113091 T326 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> 113108 T299 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 113109 T299 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 113111 T299 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55405
[junit4] 2> 113112 T299 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 113112 T299 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 113112 T299 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-003
[junit4] 2> 113113 T299 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-003/'
[junit4] 2> 113123 T299 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-003/solr.xml
[junit4] 2> 113139 T299 oasc.CoreContainer.<init> New CoreContainer 4903192
[junit4] 2> 113139 T299 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-003/]
[junit4] 2> 113140 T299 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 113140 T299 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 113141 T299 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 113141 T299 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 113141 T299 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 113142 T299 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 113142 T299 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 113142 T299 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 113143 T299 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 113144 T299 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 113144 T299 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 113144 T299 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 113145 T299 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 113145 T299 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43639/solr
[junit4] 2> 113146 T299 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 113146 T299 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 113147 T299 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 113149 T344 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6adc31 name:ZooKeeperConnection Watcher:127.0.0.1:43639 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 113150 T299 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 113151 T299 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 113153 T299 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 113154 T346 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@88b1a2 name:ZooKeeperConnection Watcher:127.0.0.1:43639/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 113154 T299 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 113160 T299 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 114162 T299 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55405_gb_k
[junit4] 2> 114163 T299 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55405_gb_k
[junit4] 2> 114166 T299 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 114169 T348 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 114169 T348 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 114170 T326 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 114170 T348 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 114171 T322 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:55405/gb_k",
[junit4] 2> "node_name":"127.0.0.1:55405_gb_k",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 114171 T322 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 114172 T322 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 114274 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 114274 T326 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 114274 T347 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 115170 T348 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 115171 T348 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 115171 T348 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 115172 T348 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 115172 T348 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 115173 T348 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-003/collection1/'
[junit4] 2> 115173 T348 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 115173 T348 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 115174 T348 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 115196 T348 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 115207 T348 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 115209 T348 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 115214 T348 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 115318 T348 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 115318 T348 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 115319 T348 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 115322 T348 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 115324 T348 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 115334 T348 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 115348 T348 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 115350 T348 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 115351 T348 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 115351 T348 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 115351 T348 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 115352 T348 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 115352 T348 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 115352 T348 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 115352 T348 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 115353 T348 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-003/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty1/
[junit4] 2> 115353 T348 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@8564dd
[junit4] 2> 115353 T348 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty1
[junit4] 2> 115354 T348 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty1/index/
[junit4] 2> 115354 T348 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 115354 T348 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty1/index
[junit4] 2> 115354 T348 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=42, maxMergedSegmentMB=84.595703125, floorSegmentMB=1.4208984375, forceMergeDeletesPctAllowed=29.309084928402118, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 115355 T348 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-497ebb)),segFN=segments_1,generation=1}
[junit4] 2> 115355 T348 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 115359 T348 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 115359 T348 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 115360 T348 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 115360 T348 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 115360 T348 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 115360 T348 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 115360 T348 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 115361 T348 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 115361 T348 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 115361 T348 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 115362 T348 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 115362 T348 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 115362 T348 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 115363 T348 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 115363 T348 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 115363 T348 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 115364 T348 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 115364 T348 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 115364 T348 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 115366 T348 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 115366 T348 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 115367 T348 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 115368 T348 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 115369 T348 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 115370 T348 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 115370 T348 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=35, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=34.8740234375, floorSegmentMB=1.4296875, forceMergeDeletesPctAllowed=9.470844257815504, segmentsPerTier=32.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 115371 T348 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-497ebb)),segFN=segments_1,generation=1}
[junit4] 2> 115371 T348 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 115371 T348 oass.SolrIndexSearcher.<init> Opening Searcher@35cbc8[collection1] main
[junit4] 2> 115371 T348 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 115372 T348 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 115372 T348 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 115373 T348 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 115373 T348 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 115373 T348 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 115373 T348 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
[junit4] 2> 115374 T348 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 115374 T348 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
[junit4] 2> 115374 T348 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 115377 T349 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@35cbc8[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 115379 T348 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 115381 T352 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55405/gb_k collection:collection1 shard:shard2
[junit4] 2> 115381 T299 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 115381 T299 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 115381 T352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 115388 T352 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 115390 T326 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 115391 T352 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 115391 T352 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C53 name=collection1 org.apache.solr.core.SolrCore@130bfa6 url=http://127.0.0.1:55405/gb_k/collection1 node=127.0.0.1:55405_gb_k C53_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:55405/gb_k, node_name=127.0.0.1:55405_gb_k, state=down}
[junit4] 2> 115391 T352 C53 P55405 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55405/gb_k/collection1/
[junit4] 2> 115392 T352 C53 P55405 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 115392 T352 C53 P55405 oasc.SyncStrategy.syncToMe http://127.0.0.1:55405/gb_k/collection1/ has no replicas
[junit4] 2> 115392 T352 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55405/gb_k/collection1/ shard2
[junit4] 2> 115392 T352 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 115396 T326 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 115501 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 115501 T326 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 115502 T347 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 115550 T352 oasc.ZkController.register We are http://127.0.0.1:55405/gb_k/collection1/ and leader is http://127.0.0.1:55405/gb_k/collection1/
[junit4] 2> 115550 T352 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55405/gb_k
[junit4] 2> 115550 T352 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 115550 T352 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 115551 T352 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 115552 T326 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 115554 T322 oasc.Overseer$ClusterStateUpdater.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:55405/gb_k",
[junit4] 2> "node_name":"127.0.0.1:55405_gb_k",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 115637 T299 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 115638 T299 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 115640 T299 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41920
[junit4] 2> 115644 T299 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 115645 T299 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 115645 T299 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-004
[junit4] 2> 115645 T299 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-004/'
[junit4] 2> 115659 T347 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 115659 T326 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 115659 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 115669 T299 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-004/solr.xml
[junit4] 2> 115678 T299 oasc.CoreContainer.<init> New CoreContainer 5997852
[junit4] 2> 115679 T299 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-004/]
[junit4] 2> 115680 T299 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 115680 T299 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 115680 T299 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 115681 T299 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 115681 T299 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 115681 T299 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 115682 T299 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 115682 T299 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 115682 T299 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 115683 T299 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 115684 T299 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 115684 T299 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 115684 T299 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 115685 T299 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43639/solr
[junit4] 2> 115685 T299 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 115686 T299 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 115686 T299 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 115688 T363 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d1307d name:ZooKeeperConnection Watcher:127.0.0.1:43639 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 115688 T299 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 115689 T299 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 115691 T299 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 115696 T365 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d4499d name:ZooKeeperConnection Watcher:127.0.0.1:43639/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 115696 T299 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 115700 T299 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 116703 T299 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41920_gb_k
[junit4] 2> 116704 T299 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:41920_gb_k
[junit4] 2> 116708 T299 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 116712 T367 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 116712 T367 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 116713 T326 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 116713 T367 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 116715 T322 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:41920/gb_k",
[junit4] 2> "node_name":"127.0.0.1:41920_gb_k",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 116715 T322 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 116715 T322 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 116818 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 116818 T326 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 116818 T366 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 116818 T347 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 117714 T367 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 117714 T367 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 117715 T367 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 117716 T367 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 117717 T367 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 117718 T367 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-004/collection1/'
[junit4] 2> 117719 T367 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 117719 T367 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 117720 T367 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 117757 T367 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 117773 T367 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 117775 T367 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 117780 T367 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 117925 T367 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 117926 T367 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 117932 T367 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 117936 T367 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 117938 T367 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 117948 T367 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 117951 T367 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 117954 T367 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 117955 T367 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 117955 T367 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 117955 T367 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 117956 T367 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 117956 T367 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 117956 T367 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 117957 T367 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 117957 T367 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-004/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty2/
[junit4] 2> 117957 T367 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@8564dd
[junit4] 2> 117958 T367 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty2
[junit4] 2> 117959 T367 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty2/index/
[junit4] 2> 117959 T367 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 117960 T367 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty2/index
[junit4] 2> 117960 T367 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=42, maxMergedSegmentMB=84.595703125, floorSegmentMB=1.4208984375, forceMergeDeletesPctAllowed=29.309084928402118, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 117961 T367 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1735838)),segFN=segments_1,generation=1}
[junit4] 2> 117961 T367 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 117966 T367 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 117966 T367 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 117967 T367 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 117967 T367 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 117967 T367 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 117967 T367 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 117968 T367 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 117968 T367 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 117968 T367 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 117969 T367 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 117970 T367 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 117970 T367 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 117971 T367 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 117971 T367 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 117971 T367 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 117971 T367 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 117972 T367 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 117972 T367 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 117972 T367 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 117974 T367 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 117975 T367 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 117975 T367 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 117976 T367 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 117978 T367 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 117978 T367 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 117979 T367 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=35, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=34.8740234375, floorSegmentMB=1.4296875, forceMergeDeletesPctAllowed=9.470844257815504, segmentsPerTier=32.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 117979 T367 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1735838)),segFN=segments_1,generation=1}
[junit4] 2> 117979 T367 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 117980 T367 oass.SolrIndexSearcher.<init> Opening Searcher@902794[collection1] main
[junit4] 2> 117980 T367 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 117981 T367 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 117981 T367 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 117981 T367 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 117982 T367 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 117982 T367 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 117983 T367 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
[junit4] 2> 117983 T367 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 117983 T367 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
[junit4] 2> 117983 T367 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 117987 T368 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@902794[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 117990 T367 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 117995 T371 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:41920/gb_k collection:collection1 shard:shard1
[junit4] 2> 117995 T299 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 117995 T299 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 117995 T371 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 117999 T371 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 118001 T326 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 118001 T371 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 118001 T371 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C54 name=collection1 org.apache.solr.core.SolrCore@ed2aa url=http://127.0.0.1:41920/gb_k/collection1 node=127.0.0.1:41920_gb_k C54_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:41920/gb_k, node_name=127.0.0.1:41920_gb_k, state=down}
[junit4] 2> 118001 T371 C54 P41920 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:41920/gb_k/collection1/
[junit4] 2> 118002 T371 C54 P41920 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 118002 T371 C54 P41920 oasc.SyncStrategy.syncToMe http://127.0.0.1:41920/gb_k/collection1/ has no replicas
[junit4] 2> 118002 T371 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:41920/gb_k/collection1/ shard1
[junit4] 2> 118002 T371 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 118006 T326 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 118110 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 118110 T326 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 118110 T366 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 118110 T347 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 118158 T371 oasc.ZkController.register We are http://127.0.0.1:41920/gb_k/collection1/ and leader is http://127.0.0.1:41920/gb_k/collection1/
[junit4] 2> 118158 T371 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:41920/gb_k
[junit4] 2> 118158 T371 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 118158 T371 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 118158 T371 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 118159 T326 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 118161 T322 oasc.Overseer$ClusterStateUpdater.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:41920/gb_k",
[junit4] 2> "node_name":"127.0.0.1:41920_gb_k",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 118258 T299 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 118258 T299 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 118260 T299 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44851
[junit4] 2> 118260 T299 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 118261 T299 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 118261 T299 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-005
[junit4] 2> 118261 T299 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-005/'
[junit4] 2> 118264 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 118264 T366 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 118265 T326 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 118265 T347 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 118275 T299 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-005/solr.xml
[junit4] 2> 118282 T299 oasc.CoreContainer.<init> New CoreContainer 20141812
[junit4] 2> 118283 T299 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-005/]
[junit4] 2> 118283 T299 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 118283 T299 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 118284 T299 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 118284 T299 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 118284 T299 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 118284 T299 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 118285 T299 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 118285 T299 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 118285 T299 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 118286 T299 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 118286 T299 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 118286 T299 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 118286 T299 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 118287 T299 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43639/solr
[junit4] 2> 118287 T299 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 118287 T299 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 118295 T299 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 118297 T382 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@121e997 name:ZooKeeperConnection Watcher:127.0.0.1:43639 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 118298 T299 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 118298 T299 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 118300 T299 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 118301 T384 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@80c28f name:ZooKeeperConnection Watcher:127.0.0.1:43639/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 118302 T299 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 118305 T299 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 119308 T299 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44851_gb_k
[junit4] 2> 119309 T299 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44851_gb_k
[junit4] 2> 119312 T299 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 119316 T386 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 119316 T386 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 119317 T386 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 119317 T326 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 119318 T322 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:44851/gb_k",
[junit4] 2> "node_name":"127.0.0.1:44851_gb_k",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 119319 T322 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 119319 T322 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 119422 T366 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 119422 T385 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 119422 T347 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has oc
[...truncated too long message...]
oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 153398 T455 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 153398 T299 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@eca189
[junit4] 2> 153400 T460 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:34093/gb_k",
[junit4] 2> "node_name":"127.0.0.1:34093_gb_k",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 153402 T442 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> 153403 T455 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> 153407 T299 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=7,autocommits=0,soft autocommits=1,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=1,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=42,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=6603,transaction_logs_total_number=6}
[junit4] 2> 153408 T299 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 153408 T299 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 153409 T299 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> ASYNC NEW_CORE C104 name=collection1 org.apache.solr.core.SolrCore@eca189 url=http://127.0.0.1:34093/gb_k/collection1 node=127.0.0.1:34093_gb_k C104_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:34093/gb_k, node_name=127.0.0.1:34093_gb_k, state=down, leader=true}
[junit4] 2> 153409 T299 C104 P34093 oasu.DirectUpdateHandler2.closeWriter Committing on IndexWriter close.
[junit4] 2> 153410 T299 C104 P34093 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1475f93)),segFN=segments_7,generation=7}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1475f93)),segFN=segments_8,generation=8}
[junit4] 2> 153410 T299 C104 P34093 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 8
[junit4] 2> 153411 T299 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 153412 T299 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 153412 T299 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty4/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty4/index;done=false>>]
[junit4] 2> 153413 T299 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty4/index
[junit4] 2> 153413 T299 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty4 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty4;done=false>>]
[junit4] 2> 153413 T299 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001/tempDir-001/jetty4
[junit4] 2> 153414 T299 oasc.Overseer.close Overseer (id=92475766644080652-127.0.0.1:34093_gb_k-n_0000000004) closing
[junit4] 2> 153414 T460 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:34093_gb_k
[junit4] 2> 153419 T455 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 153442 T299 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/gb_k,null}
[junit4] 2> 154919 T463 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:347)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:344)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:344)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:357)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:126)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:329)
[junit4] 2>
[junit4] 2> 158433 T299 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 158434 T299 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:43639 43639
[junit4] 2> 159279 T300 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:43639 43639
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=F7A2FC7A28D904D9 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_GT -Dtests.timezone=America/Caracas -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 48.3s J0 | BasicDistributedZkTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: commitWithin did not work on node: http://127.0.0.1:55405/gb_k/collection1 expected:<68> but was:<67>
[junit4] > at __randomizedtesting.SeedInfo.seed([F7A2FC7A28D904D9:764472625F8664E5]:0)
[junit4] > at org.apache.solr.cloud.BasicDistributedZkTest.doTest(BasicDistributedZkTest.java:355)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:871)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 159389 T299 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.BasicDistributedZkTest-F7A2FC7A28D904D9-001
[junit4] 2> 48303 T298 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Lucene42, sim=DefaultSimilarity, locale=es_GT, timezone=America/Caracas
[junit4] 2> NOTE: Linux 3.13.0-35-generic i386/Oracle Corporation 1.9.0-ea (32-bit)/cpus=8,threads=1,free=20823072,total=86974464
[junit4] 2> NOTE: All tests run in this JVM: [TestConfigSets, TestHashPartitioner, DistributedSpellCheckComponentTest, TestExpandComponent, ChangedSchemaMergeTest, ResponseHeaderTest, UpdateParamsTest, QueryResultKeyTest, ZkControllerTest, HdfsWriteToMultipleCollectionsTest, TestRemoteStreaming, TestHighFrequencyDictionaryFactory, StressHdfsTest, TestManagedSynonymFilterFactory, BasicDistributedZkTest]
[junit4] Completed on J0 in 48.58s, 1 test, 1 failure <<< FAILURES!
[...truncated 1274 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:471: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:60: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/extra-targets.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/common-build.xml:494: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/lucene/common-build.xml:1360: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/lucene/common-build.xml:963: There were test failures: 426 suites, 1779 tests, 1 failure, 44 ignored (22 assumptions)
Total time: 90 minutes 30 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 32bit/jdk1.9.0-ea-b28 -server -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
[JENKINS] Lucene-Solr-5.x-Linux (64bit/jdk1.9.0-ea-b28) - Build #
11134 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-5.x-Linux/11134/
Java: 64bit/jdk1.9.0-ea-b28 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.DeleteLastCustomShardedReplicaTest.testDistribSearch
Error Message:
No live SolrServers available to handle this request:[https://127.0.0.1:46255/x_bn, https://127.0.0.1:55162/x_bn, https://127.0.0.1:52991/x_bn]
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[https://127.0.0.1:46255/x_bn, https://127.0.0.1:55162/x_bn, https://127.0.0.1:52991/x_bn]
at __randomizedtesting.SeedInfo.seed([B92EEB02FD1E4DE3:38C8651A8A412DDF]:0)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:322)
at org.apache.solr.client.solrj.impl.CloudSolrServer.sendRequest(CloudSolrServer.java:874)
at org.apache.solr.client.solrj.impl.CloudSolrServer.requestWithRetryOnStaleState(CloudSolrServer.java:658)
at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:601)
at org.apache.solr.cloud.DeleteLastCustomShardedReplicaTest.removeAndWaitForLastReplicaGone(DeleteLastCustomShardedReplicaTest.java:117)
at org.apache.solr.cloud.DeleteLastCustomShardedReplicaTest.doTest(DeleteLastCustomShardedReplicaTest.java:107)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869)
at sun.reflect.GeneratedMethodAccessor38.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:484)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Could not remove replica : customcollreplicadeletion/a/core_node2
at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:550)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.doRequest(LBHttpSolrServer.java:343)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:304)
... 45 more
Build Log:
[...truncated 14108 lines...]
[junit4] Suite: org.apache.solr.cloud.DeleteLastCustomShardedReplicaTest
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/init-core-data-001
[junit4] 2> 2183148 T6093 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
[junit4] 2> 2183148 T6093 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /x_bn/
[junit4] 2> 2183151 T6093 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 2183152 T6093 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2183152 T6094 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2183252 T6093 oasc.ZkTestServer.run start zk server on port:33243
[junit4] 2> 2183253 T6093 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2183253 T6093 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2183300 T6100 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c350ba1 name:ZooKeeperConnection Watcher:127.0.0.1:33243 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2183301 T6093 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2183301 T6093 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2183301 T6093 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2183306 T6093 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2183307 T6093 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2183308 T6102 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61333d2a name:ZooKeeperConnection Watcher:127.0.0.1:33243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2183308 T6093 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2183309 T6093 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2183309 T6093 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 2183312 T6093 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 2183315 T6093 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 2183316 T6093 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 2183319 T6093 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 2183319 T6093 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 2183323 T6093 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 2183324 T6093 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 2183327 T6093 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2183330 T6093 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2183334 T6093 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 2183335 T6093 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 2183338 T6093 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 2183341 T6093 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 2183344 T6093 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 2183345 T6093 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 2183348 T6093 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 2183349 T6093 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 2183351 T6093 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 2183352 T6093 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 2183355 T6093 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2183356 T6093 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2183358 T6093 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 2183359 T6093 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 2183361 T6093 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 2183362 T6093 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 2183364 T6093 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2183365 T6093 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2183365 T6104 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55b36f6a name:ZooKeeperConnection Watcher:127.0.0.1:33243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2183366 T6093 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2183366 T6093 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2184188 T6093 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2184192 T6093 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 2184366 T6093 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:46255
[junit4] 2> 2184368 T6093 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2184369 T6093 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2184369 T6093 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-002
[junit4] 2> 2184370 T6093 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-002/'
[junit4] 2> 2184392 T6093 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-002/solr.xml
[junit4] 2> 2184398 T6093 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-002
[junit4] 2> 2184399 T6093 oasc.CoreContainer.<init> New CoreContainer 1881409865
[junit4] 2> 2184399 T6093 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-002/]
[junit4] 2> 2184399 T6093 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2184399 T6093 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2184400 T6093 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2184400 T6093 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2184400 T6093 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2184400 T6093 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2184400 T6093 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2184401 T6093 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2184401 T6093 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2184402 T6093 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 2184402 T6093 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2184403 T6093 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2184403 T6093 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2184403 T6093 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33243/solr
[junit4] 2> 2184403 T6093 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2184403 T6093 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2184404 T6093 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2184405 T6115 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39ce5e52 name:ZooKeeperConnection Watcher:127.0.0.1:33243 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2184406 T6093 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2184406 T6093 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2184407 T6093 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2184407 T6117 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b03e202 name:ZooKeeperConnection Watcher:127.0.0.1:33243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2184408 T6093 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2184408 T6093 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2184411 T6093 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2184412 T6093 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2184413 T6093 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2184414 T6093 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2184416 T6093 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2184416 T6093 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46255_x_bn
[junit4] 2> 2184417 T6093 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46255_x_bn
[junit4] 2> 2184418 T6093 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2184418 T6093 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2184419 T6093 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 2184420 T6093 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:46255_x_bn
[junit4] 2> 2184421 T6093 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2184422 T6093 oasc.Overseer.start Overseer (id=92476752476438532-127.0.0.1:46255_x_bn-n_0000000000) starting
[junit4] 2> 2184423 T6093 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2184427 T6093 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=10000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 2184428 T6119 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2184428 T6093 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2184433 T6093 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2184434 T6093 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2184437 T6118 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2184533 T6093 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-002
[junit4] 2> 2184541 T6093 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-002/conf/
[junit4] 2> 2184677 T6093 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 2184678 T6093 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 2184678 T6093 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2184680 T6093 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2184680 T6093 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2184682 T6123 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79407e2f name:ZooKeeperConnection Watcher:127.0.0.1:33243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2184682 T6093 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2184682 T6093 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2184684 T6093 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2184687 T6093 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 2184687 T6093 oasc.AbstractFullDistribZkTestBase.createJettys Creating collection1 with stateFormat=2
[junit4] 2> 2184688 T6093 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2184688 T6093 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2184689 T6125 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e3972c2 name:ZooKeeperConnection Watcher:127.0.0.1:33243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2184689 T6093 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2184690 T6093 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2184691 T6126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2184693 T6118 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: collection1
[junit4] 2> 2184694 T6118 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 2184694 T6118 oasc.Overseer$ClusterStateUpdater.createCollection state version collection1 2
[junit4] 2> 2184695 T6118 oasc.Overseer$ClusterStateUpdater.updateZkStates going to create_collection /collections/collection1/state.json
[junit4] 2> 2184696 T6126 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> 2184696 T6127 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> 2185490 T6093 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 2185491 T6093 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2185493 T6093 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 2185494 T6093 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:52991
[junit4] 2> 2185497 T6093 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2185498 T6093 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2185499 T6093 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-003
[junit4] 2> 2185500 T6093 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-003/'
[junit4] 2> 2185510 T6093 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-003/solr.xml
[junit4] 2> 2185515 T6093 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-003
[junit4] 2> 2185516 T6093 oasc.CoreContainer.<init> New CoreContainer 1609177901
[junit4] 2> 2185516 T6093 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-003/]
[junit4] 2> 2185517 T6093 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2185517 T6093 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2185517 T6093 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2185517 T6093 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2185517 T6093 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2185518 T6093 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2185518 T6093 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2185518 T6093 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2185518 T6093 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2185519 T6093 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 2185520 T6093 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2185520 T6093 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2185520 T6093 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2185521 T6093 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33243/solr
[junit4] 2> 2185521 T6093 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2185521 T6093 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2185522 T6093 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2185523 T6138 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f8dd01e name:ZooKeeperConnection Watcher:127.0.0.1:33243 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2185523 T6093 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2185523 T6093 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2185524 T6093 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2185525 T6140 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a43bc36 name:ZooKeeperConnection Watcher:127.0.0.1:33243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2185525 T6093 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2185529 T6093 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2186532 T6093 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52991_x_bn
[junit4] 2> 2186533 T6093 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52991_x_bn
[junit4] 2> 2186551 T6093 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 2186553 T6093 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-003
[junit4] 2> 2186559 T6093 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-003/conf/
[junit4] 2> 2186697 T6093 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 2186697 T6093 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 2186698 T6093 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2186945 T6093 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 2186945 T6093 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2186948 T6093 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 2186948 T6093 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:55162
[junit4] 2> 2186949 T6093 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2186950 T6093 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2186950 T6093 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-004
[junit4] 2> 2186950 T6093 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-004/'
[junit4] 2> 2186961 T6093 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-004/solr.xml
[junit4] 2> 2186967 T6093 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-004
[junit4] 2> 2186967 T6093 oasc.CoreContainer.<init> New CoreContainer 163314214
[junit4] 2> 2186967 T6093 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-004/]
[junit4] 2> 2186968 T6093 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2186968 T6093 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2186968 T6093 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2186969 T6093 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2186969 T6093 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2186969 T6093 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2186969 T6093 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2186969 T6093 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2186970 T6093 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2186971 T6093 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 2186971 T6093 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2186971 T6093 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2186972 T6093 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2186972 T6093 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33243/solr
[junit4] 2> 2186972 T6093 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2186972 T6093 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2186973 T6093 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2186974 T6153 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@46964bd8 name:ZooKeeperConnection Watcher:127.0.0.1:33243 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2186974 T6093 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2186974 T6093 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2186975 T6093 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2186976 T6155 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3951b18c name:ZooKeeperConnection Watcher:127.0.0.1:33243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2186976 T6093 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2186979 T6093 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2187981 T6093 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55162_x_bn
[junit4] 2> 2187982 T6093 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55162_x_bn
[junit4] 2> 2187986 T6093 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 2187988 T6093 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-004
[junit4] 2> 2187993 T6093 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-004/conf/
[junit4] 2> 2188098 T6093 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 2188099 T6093 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 2188099 T6093 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2188101 T6093 oasc.AbstractFullDistribZkTestBase.createCollection Creating collection with stateFormat=2: customcollreplicadeletion
[junit4] 2> 2188102 T6093 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2188102 T6093 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2188103 T6159 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ee0996e name:ZooKeeperConnection Watcher:127.0.0.1:33243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2188103 T6093 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2188103 T6093 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2188104 T6093 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2188191 T6134 oasha.CollectionsHandler.handleCreateAction Creating Collection : replicationFactor=1&shards=a,b&maxShardsPerNode=5&router.name=implicit&name=customcollreplicadeletion&action=CREATE&numShards=1&stateFormat=2&wt=javabin&version=2
[junit4] 2> 2188192 T6126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2188192 T6119 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4] 2> "operation":"create",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"customcollreplicadeletion",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "numShards":"1",
[junit4] 2> "maxShardsPerNode":"5",
[junit4] 2> "shards":"a,b",
[junit4] 2> "stateFormat":"2",
[junit4] 2> "router.name":"implicit"}
[junit4] 2> 2188194 T6160 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : create , {
[junit4] 2> "operation":"create",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"customcollreplicadeletion",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "numShards":"1",
[junit4] 2> "maxShardsPerNode":"5",
[junit4] 2> "shards":"a,b",
[junit4] 2> "stateFormat":"2",
[junit4] 2> "router.name":"implicit"}
[junit4] 2> 2188195 T6160 oasc.OverseerCollectionProcessor.createConfNode Only one config set found in zk - using it:conf1
[junit4] 2> 2188195 T6160 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/customcollreplicadeletion
[junit4] 2> 2188195 T6160 oascc.SolrZkClient.makePath makePath: /collections/customcollreplicadeletion
[junit4] 2> 2188197 T6126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2188198 T6118 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: customcollreplicadeletion
[junit4] 2> 2188198 T6118 oasc.Overseer$ClusterStateUpdater.createCollection Create collection customcollreplicadeletion with shards [a, b]
[junit4] 2> 2188198 T6118 oasc.Overseer$ClusterStateUpdater.createCollection state version customcollreplicadeletion 2
[junit4] 2> 2188199 T6118 oasc.Overseer$ClusterStateUpdater.updateZkStates going to create_collection /collections/customcollreplicadeletion/state.json
[junit4] 2> 2188200 T6141 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2188200 T6126 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2188200 T6156 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2188200 T6127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2188200 T6161 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2188297 T6160 oasc.OverseerCollectionProcessor.createCollection Creating SolrCores for new collection customcollreplicadeletion, shardNames [a, b] , replicationFactor : 1
[junit4] 2> 2188297 T6160 oasc.OverseerCollectionProcessor.createCollection Creating shard customcollreplicadeletion_a_replica1 as part of slice a of collection customcollreplicadeletion on 127.0.0.1:46255_x_bn
[junit4] 2> 2188298 T6160 oasc.OverseerCollectionProcessor.createCollection Creating shard customcollreplicadeletion_b_replica1 as part of slice b of collection customcollreplicadeletion on 127.0.0.1:52991_x_bn
[junit4] 2> 2188394 T6133 oasha.CoreAdminHandler.handleCreateAction core create command qt=/admin/cores&collection.configName=conf1&name=customcollreplicadeletion_b_replica1&action=CREATE&numShards=2&collection=customcollreplicadeletion&shard=b&wt=javabin&version=2
[junit4] 2> 2188396 T6133 oasc.ZkController.publish publishing core=customcollreplicadeletion_b_replica1 state=down collection=customcollreplicadeletion
[junit4] 2> 2188399 T6113 oasha.CoreAdminHandler.handleCreateAction core create command qt=/admin/cores&collection.configName=conf1&name=customcollreplicadeletion_a_replica1&action=CREATE&numShards=2&collection=customcollreplicadeletion&shard=a&wt=javabin&version=2
[junit4] 2> 2188400 T6126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2188400 T6133 oasc.ZkController.preRegister Registering watch for external collection customcollreplicadeletion
[junit4] 2> 2188400 T6133 oascc.ZkStateReader.addZkWatch addZkWatch customcollreplicadeletion
[junit4] 2> 2188401 T6133 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/customcollreplicadeletion/state.json from ZooKeeper...
[junit4] 2> 2188401 T6133 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 0
[junit4] 2> 2188402 T6133 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2188402 T6113 oasc.ZkController.publish publishing core=customcollreplicadeletion_a_replica1 state=down collection=customcollreplicadeletion
[junit4] 2> 2188402 T6118 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "core":"customcollreplicadeletion_b_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:52991/x_bn",
[junit4] 2> "node_name":"127.0.0.1:52991_x_bn",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"b",
[junit4] 2> "collection":"customcollreplicadeletion",
[junit4] 2> "operation":"state"}
[junit4] 2> 2188403 T6113 oasc.ZkController.preRegister Registering watch for external collection customcollreplicadeletion
[junit4] 2> 2188413 T6118 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/customcollreplicadeletion/state.json
[junit4] 2> 2188414 T6141 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2188414 T6141 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 1
[junit4] 2> 2188414 T6113 oascc.ZkStateReader.addZkWatch addZkWatch customcollreplicadeletion
[junit4] 2> 2188415 T6113 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/customcollreplicadeletion/state.json from ZooKeeper...
[junit4] 2> 2188416 T6113 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 1
[junit4] 2> 2188416 T6113 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2188417 T6118 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 1
[junit4] 2> 2188418 T6118 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "core":"customcollreplicadeletion_a_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:46255/x_bn",
[junit4] 2> "node_name":"127.0.0.1:46255_x_bn",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"a",
[junit4] 2> "collection":"customcollreplicadeletion",
[junit4] 2> "operation":"state"}
[junit4] 2> 2188419 T6126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2188419 T6118 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/customcollreplicadeletion/state.json
[junit4] 2> 2188419 T6126 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2188419 T6141 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2188420 T6141 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 2
[junit4] 2> 2188420 T6126 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 2
[junit4] 2> 2189402 T6133 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for customcollreplicadeletion_b_replica1
[junit4] 2> 2189402 T6133 oasc.ZkController.createCollectionZkNode Check for collection zkNode:customcollreplicadeletion
[junit4] 2> 2189403 T6133 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2189403 T6133 oascc.ZkStateReader.readConfigName Load collection config from:/collections/customcollreplicadeletion
[junit4] 2> 2189403 T6133 oascc.ZkStateReader.readConfigName path=/collections/customcollreplicadeletion configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2189404 T6133 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-003/customcollreplicadeletion_b_replica1/'
[junit4] 2> 2189416 T6113 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for customcollreplicadeletion_a_replica1
[junit4] 2> 2189417 T6113 oasc.ZkController.createCollectionZkNode Check for collection zkNode:customcollreplicadeletion
[junit4] 2> 2189417 T6113 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2189417 T6113 oascc.ZkStateReader.readConfigName Load collection config from:/collections/customcollreplicadeletion
[junit4] 2> 2189418 T6113 oascc.ZkStateReader.readConfigName path=/collections/customcollreplicadeletion configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2189418 T6113 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-002/customcollreplicadeletion_a_replica1/'
[junit4] 2> 2189422 T6133 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 2189434 T6133 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2189435 T6133 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2189435 T6113 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 2189445 T6133 oass.IndexSchema.readSchema [customcollreplicadeletion_b_replica1] Schema name=test
[junit4] 2> 2189452 T6113 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2189453 T6113 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2189457 T6113 oass.IndexSchema.readSchema [customcollreplicadeletion_a_replica1] Schema name=test
[junit4] 2> 2189551 T6133 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2189554 T6133 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2189556 T6133 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2189561 T6133 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2189564 T6133 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2189565 T6133 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2189566 T6133 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2189566 T6133 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2189566 T6133 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2189567 T6133 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2189567 T6133 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2189567 T6133 oasc.CoreContainer.create Creating SolrCore 'customcollreplicadeletion_b_replica1' using configuration from collection customcollreplicadeletion
[junit4] 2> 2189567 T6133 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2189568 T6133 oasc.SolrCore.<init> [customcollreplicadeletion_b_replica1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-003/customcollreplicadeletion_b_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-003/customcollreplicadeletion_b_replica1/data/
[junit4] 2> 2189568 T6133 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@231b3301
[junit4] 2> 2189568 T6133 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-003/customcollreplicadeletion_b_replica1/data
[junit4] 2> 2189569 T6133 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-003/customcollreplicadeletion_b_replica1/data/index/
[junit4] 2> 2189569 T6133 oasc.SolrCore.initIndex WARN [customcollreplicadeletion_b_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-003/customcollreplicadeletion_b_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 2189569 T6133 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-003/customcollreplicadeletion_b_replica1/data/index
[junit4] 2> 2189570 T6113 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2189570 T6133 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=27, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 2189571 T6133 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-4ab2441a)),segFN=segments_1,generation=1}
[junit4] 2> 2189571 T6133 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2189573 T6113 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2189573 T6133 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2189573 T6133 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2189574 T6133 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2189574 T6133 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2189574 T6133 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2189574 T6113 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2189574 T6133 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2189575 T6133 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2189575 T6133 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2189575 T6133 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2189576 T6133 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2189576 T6133 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2189576 T6133 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2189577 T6133 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2189577 T6133 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2189577 T6133 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2189578 T6133 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2189578 T6133 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2189578 T6133 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2189579 T6133 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2189579 T6133 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 2189580 T6113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2189582 T6133 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2189582 T6113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2189583 T6133 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2189584 T6113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2189584 T6133 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2189584 T6113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2189584 T6113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2189585 T6113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2189585 T6133 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2189585 T6113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2189585 T6113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2189586 T6113 oasc.CoreContainer.create Creating SolrCore 'customcollreplicadeletion_a_replica1' using configuration from collection customcollreplicadeletion
[junit4] 2> 2189586 T6113 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2189586 T6113 oasc.SolrCore.<init> [customcollreplicadeletion_a_replica1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-002/customcollreplicadeletion_a_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-002/customcollreplicadeletion_a_replica1/data/
[junit4] 2> 2189587 T6113 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@231b3301
[junit4] 2> 2189587 T6133 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2189587 T6133 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2189588 T6113 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-002/customcollreplicadeletion_a_replica1/data
[junit4] 2> 2189588 T6113 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-002/customcollreplicadeletion_a_replica1/data/index/
[junit4] 2> 2189588 T6133 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=954583276, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 2189588 T6113 oasc.SolrCore.initIndex WARN [customcollreplicadeletion_a_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-002/customcollreplicadeletion_a_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 2189589 T6133 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-4ab2441a)),segFN=segments_1,generation=1}
[junit4] 2> 2189589 T6133 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2189589 T6113 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001/tempDir-002/customcollreplicadeletion_a_replica1/data/index
[junit4] 2> 2189589 T6133 oass.SolrIndexSearcher.<init> Opening Searcher@d7aaad1[customcollreplicadeletion_b_replica1] main
[junit4] 2> 2189590 T6113 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=27, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 2189590 T6133 oascc.ZkStateReader.readConfigName Load collection config from:/collections/customcollreplicadeletion
[junit4] 2> 2189590 T6113 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-687be81)),segFN=segments_1,generation=1}
[junit4] 2> 2189591 T6113 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2189591 T6133 oascc.ZkStateReader.readConfigName path=/collections/customcollreplicadeletion configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2189591 T6133 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2189592 T6133 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2189592 T6133 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2189592 T6133 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2189593 T6133 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 2189593 T6133 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2189593 T6113 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2189593 T6133 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json
[junit4] 2> 2189594 T6113 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2189594 T6113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2189594 T6113 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2189594 T6113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2189594 T6133 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json
[junit4] 2> 2189595 T6133 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2189595 T6113 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2189595 T6133 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2189596 T6113 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2189596 T6113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2189596 T6113 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2189597 T6113 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2189597 T6113 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2189597 T6113 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2189598 T6113 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2189598 T6164 oasc.SolrCore.registerSearcher [customcollreplicadeletion_b_replica1] Registered new searcher Searcher@d7aaad1[customcollreplicadeletion_b_replica1] main{UninvertingDirectoryReader()}
[junit4] 2> 2189598 T6113 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2189598 T6113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2189598 T6113 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2189599 T6113 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2189599 T6113 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2189599 T6133 oasc.CoreContainer.registerCore registering core: customcollreplicadeletion_b_replica1
[junit4] 2> 2189599 T6113 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2189600 T6133 oasc.ZkController.register Register replica - core:customcollreplicadeletion_b_replica1 address:https://127.0.0.1:52991/x_bn collection:customcollreplicadeletion shard:b
[junit4] 2> 2189600 T6113 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 2189600 T6133 oascc.SolrZkClient.makePath makePath: /collections/customcollreplicadeletion/leader_elect/b/election
[junit4] 2> 2189601 T6113 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2189602 T6113 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2189603 T6113 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2189603 T6133 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard b
[junit4] 2> 2189603 T6113 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2189604 T6133 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2189604 T6126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189605 T6133 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1885 name=customcollreplicadeletion_b_replica1 org.apache.solr.core.SolrCore@7494099 url=https://127.0.0.1:52991/x_bn/customcollreplicadeletion_b_replica1 node=127.0.0.1:52991_x_bn C1885_STATE=coll:customcollreplicadeletion core:customcollreplicadeletion_b_replica1 props:{core=customcollreplicadeletion_b_replica1, base_url=https://127.0.0.1:52991/x_bn, node_name=127.0.0.1:52991_x_bn, state=down}
[junit4] 2> 2189605 T6133 C1885 P52991 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:52991/x_bn/customcollreplicadeletion_b_replica1/
[junit4] 2> 2189605 T6133 C1885 P52991 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2189606 T6133 C1885 P52991 oasc.SyncStrategy.syncToMe https://127.0.0.1:52991/x_bn/customcollreplicadeletion_b_replica1/ has no replicas
[junit4] 2> 2189606 T6133 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:52991/x_bn/customcollreplicadeletion_b_replica1/ b
[junit4] 2> 2189606 T6133 oascc.SolrZkClient.makePath makePath: /collections/customcollreplicadeletion/leaders/b
[junit4] 2> 2189607 T6118 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 2
[junit4] 2> 2189607 T6113 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2189608 T6113 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2189609 T6113 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=954583276, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 2189610 T6118 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/customcollreplicadeletion/state.json
[junit4] 2> 2189610 T6113 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-687be81)),segFN=segments_1,generation=1}
[junit4] 2> 2189610 T6113 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2189610 T6141 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2189610 T6126 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2189610 T6113 oass.SolrIndexSearcher.<init> Opening Searcher@6020c691[customcollreplicadeletion_a_replica1] main
[junit4] 2> 2189611 T6113 oascc.ZkStateReader.readConfigName Load collection config from:/collections/customcollreplicadeletion
[junit4] 2> 2189611 T6141 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 3
[junit4] 2> 2189612 T6113 oascc.ZkStateReader.readConfigName path=/collections/customcollreplicadeletion configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2189612 T6113 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2189612 T6126 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 3
[junit4] 2> 2189612 T6113 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2189613 T6113 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2189613 T6113 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2189613 T6113 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
[junit4] 2> 2189614 T6113 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2189614 T6118 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 3
[junit4] 2> 2189614 T6113 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
[junit4] 2> 2189614 T6113 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2189615 T6126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189615 T6118 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/customcollreplicadeletion/state.json
[junit4] 2> 2189616 T6126 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2189616 T6141 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2189616 T6166 oasc.SolrCore.registerSearcher [customcollreplicadeletion_a_replica1] Registered new searcher Searcher@6020c691[customcollreplicadeletion_a_replica1] main{UninvertingDirectoryReader()}
[junit4] 2> 2189616 T6141 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 4
[junit4] 2> 2189617 T6126 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 4
[junit4] 2> 2189617 T6113 oasc.CoreContainer.registerCore registering core: customcollreplicadeletion_a_replica1
[junit4] 2> 2189618 T6113 oasc.ZkController.register Register replica - core:customcollreplicadeletion_a_replica1 address:https://127.0.0.1:46255/x_bn collection:customcollreplicadeletion shard:a
[junit4] 2> 2189618 T6113 oascc.SolrZkClient.makePath makePath: /collections/customcollreplicadeletion/leader_elect/a/election
[junit4] 2> 2189620 T6113 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard a
[junit4] 2> 2189621 T6126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189621 T6113 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2189621 T6113 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1886 name=customcollreplicadeletion_a_replica1 org.apache.solr.core.SolrCore@48420e70 url=https://127.0.0.1:46255/x_bn/customcollreplicadeletion_a_replica1 node=127.0.0.1:46255_x_bn C1886_STATE=coll:customcollreplicadeletion core:customcollreplicadeletion_a_replica1 props:{core=customcollreplicadeletion_a_replica1, base_url=https://127.0.0.1:46255/x_bn, node_name=127.0.0.1:46255_x_bn, state=down}
[junit4] 2> 2189622 T6113 C1886 P46255 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:46255/x_bn/customcollreplicadeletion_a_replica1/
[junit4] 2> 2189622 T6113 C1886 P46255 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2189622 T6113 C1886 P46255 oasc.SyncStrategy.syncToMe https://127.0.0.1:46255/x_bn/customcollreplicadeletion_a_replica1/ has no replicas
[junit4] 2> 2189622 T6113 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:46255/x_bn/customcollreplicadeletion_a_replica1/ a
[junit4] 2> 2189623 T6113 oascc.SolrZkClient.makePath makePath: /collections/customcollreplicadeletion/leaders/a
[junit4] 2> 2189623 T6118 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 4
[junit4] 2> 2189624 T6118 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/customcollreplicadeletion/state.json
[junit4] 2> 2189625 T6126 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2189625 T6141 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2189625 T6141 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 5
[junit4] 2> 2189626 T6126 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 5
[junit4] 2> 2189627 T6118 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 5
[junit4] 2> 2189628 T6126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189628 T6118 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/customcollreplicadeletion/state.json
[junit4] 2> 2189629 T6126 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2189629 T6141 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2189629 T6141 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 6
[junit4] 2> 2189630 T6126 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 6
[junit4] 2> 2189661 T6133 oasc.ZkController.register We are https://127.0.0.1:52991/x_bn/customcollreplicadeletion_b_replica1/ and leader is https://127.0.0.1:52991/x_bn/customcollreplicadeletion_b_replica1/
[junit4] 2> 2189662 T6133 oasc.ZkController.register No LogReplay needed for core=customcollreplicadeletion_b_replica1 baseURL=https://127.0.0.1:52991/x_bn
[junit4] 2> 2189662 T6133 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2189662 T6133 oasc.ZkController.publish publishing core=customcollreplicadeletion_b_replica1 state=active collection=customcollreplicadeletion
[junit4] 2> 2189664 T6126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189666 T6133 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 6
[junit4] 2> 2189667 T6118 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 6
[junit4] 2> 2189667 T6118 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "core":"customcollreplicadeletion_b_replica1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:52991/x_bn",
[junit4] 2> "node_name":"127.0.0.1:52991_x_bn",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"b",
[junit4] 2> "collection":"customcollreplicadeletion",
[junit4] 2> "operation":"state"}
[junit4] 2> 2189667 T6133 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&name=customcollreplicadeletion_b_replica1&action=CREATE&numShards=2&collection=customcollreplicadeletion&shard=b&wt=javabin&version=2} status=0 QTime=1273
[junit4] 2> 2189669 T6118 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/customcollreplicadeletion/state.json
[junit4] 2> 2189669 T6126 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2189669 T6141 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2189670 T6141 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 7
[junit4] 2> 2189671 T6126 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 7
[junit4] 2> 2189675 T6113 oasc.ZkController.register We are https://127.0.0.1:46255/x_bn/customcollreplicadeletion_a_replica1/ and leader is https://127.0.0.1:46255/x_bn/customcollreplicadeletion_a_replica1/
[junit4] 2> 2189676 T6113 oasc.ZkController.register No LogReplay needed for core=customcollreplicadeletion_a_replica1 baseURL=https://127.0.0.1:46255/x_bn
[junit4] 2> 2189676 T6113 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2189676 T6113 oasc.ZkController.publish publishing core=customcollreplicadeletion_a_replica1 state=active collection=customcollreplicadeletion
[junit4] 2> 2189677 T6126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189679 T6113 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 7
[junit4] 2> 2189680 T6113 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&name=customcollreplicadeletion_a_replica1&action=CREATE&numShards=2&collection=customcollreplicadeletion&shard=a&wt=javabin&version=2} status=0 QTime=1281
[junit4] 2> 2189681 T6160 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: customcollreplicadeletion
[junit4] 2> 2189681 T6118 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 7
[junit4] 2> 2189682 T6160 oasc.OverseerCollectionProcessor$Runner.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=1273},core=customcollreplicadeletion_b_replica1},null={responseHeader={status=0,QTime=1281},core=customcollreplicadeletion_a_replica1}}}
[junit4] 2> 2189683 T6141 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged
[junit4] 2> 2189683 T6118 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "core":"customcollreplicadeletion_a_replica1",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:46255/x_bn",
[junit4] 2> "node_name":"127.0.0.1:46255_x_bn",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"a",
[junit4] 2> "collection":"customcollreplicadeletion",
[junit4] 2> "operation":"state"}
[junit4] 2> 2189684 T6126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189684 T6134 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/collections params={replicationFactor=1&shards=a,b&maxShardsPerNode=5&router.name=implicit&name=customcollreplicadeletion&action=CREATE&numShards=1&stateFormat=2&wt=javabin&version=2} status=0 QTime=1493
[junit4] 2> 2189685 T6118 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/customcollreplicadeletion/state.json
[junit4] 2> 2189685 T6126 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2189685 T6093 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: customcollreplicadeletion failOnTimeout:true timeout (sec):330
[junit4] 2> 2189685 T6141 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/customcollreplicadeletion/state.json, has occurred - updating...
[junit4] 2> 2189686 T6141 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 8
[junit4] 2> 2189686 T6126 oascc.ZkStateReader.updateWatchedCollection Updating data for customcollreplicadeletion to ver 8
[junit4] 2> 2189687 T6093 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: customcollreplicadeletion
[junit4] 2> 2189688 T6093 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2189689 T6093 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2189689 T6169 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c1fa9d5 name:ZooKeeperConnection Watcher:127.0.0.1:33243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2189690 T6093 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2189690 T6093 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2189690 T6093 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2189696 T6134 oasha.CollectionsHandler.handleRemoveReplica Remove replica: replica=core_node2&action=deletereplica&collection=customcollreplicadeletion&shard=a&wt=javabin&version=2
[junit4] 2> 2189697 T6126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189698 T6119 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000002 message:{
[junit4] 2> "operation":"deletereplica",
[junit4] 2> "collection":"customcollreplicadeletion",
[junit4] 2> "shard":"a",
[junit4] 2> "replica":"core_node2"}
[junit4] 2> 2189698 T6170 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : deletereplica , {
[junit4] 2> "operation":"deletereplica",
[junit4] 2> "collection":"customcollreplicadeletion",
[junit4] 2> "shard":"a",
[junit4] 2> "replica":"core_node2"}
[junit4] 2> 2189760 T6112 oasc.SolrCore.close [customcollreplicadeletion_a_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@48420e70
[junit4] 2> 2189765 T6112 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
[junit4] 2> 2189765 T6112 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 2189765 T6112 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 2189765 T6112 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWr
[...truncated too long message...]
entCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2313935 T6159 oaz.ClientCnxn$EventThread.processEvent ERROR Error while calling watcher java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@38e644c2 rejected from java.util.concurrent.ThreadPoolExecutor@9a58fe8[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 5]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2049)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1369)
[junit4] 2> at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:112)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.process(SolrZkClient.java:263)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2313936 T6159 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ee0996e name:ZooKeeperConnection Watcher:127.0.0.1:33243/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4] 2> 2313936 T6159 oascc.ConnectionManager.process Client->ZooKeeper status change trigger but we are already closed
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=DeleteLastCustomShardedReplicaTest -Dtests.method=testDistribSearch -Dtests.seed=B92EEB02FD1E4DE3 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar_JO -Dtests.timezone=Asia/Pontianak -Dtests.file.encoding=US-ASCII
[junit4] ERROR 131s J1 | DeleteLastCustomShardedReplicaTest.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[https://127.0.0.1:46255/x_bn, https://127.0.0.1:55162/x_bn, https://127.0.0.1:52991/x_bn]
[junit4] > at __randomizedtesting.SeedInfo.seed([B92EEB02FD1E4DE3:38C8651A8A412DDF]:0)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:322)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrServer.sendRequest(CloudSolrServer.java:874)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrServer.requestWithRetryOnStaleState(CloudSolrServer.java:658)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:601)
[junit4] > at org.apache.solr.cloud.DeleteLastCustomShardedReplicaTest.removeAndWaitForLastReplicaGone(DeleteLastCustomShardedReplicaTest.java:117)
[junit4] > at org.apache.solr.cloud.DeleteLastCustomShardedReplicaTest.doTest(DeleteLastCustomShardedReplicaTest.java:107)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > Caused by: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Could not remove replica : customcollreplicadeletion/a/core_node2
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:550)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrServer.doRequest(LBHttpSolrServer.java:343)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:304)
[junit4] > ... 45 more
[junit4] 2> 2313953 T6093 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteLastCustomShardedReplicaTest-B92EEB02FD1E4DE3-001
[junit4] 2> 130809 T6092 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Lucene410: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=ar_JO, timezone=Asia/Pontianak
[junit4] 2> NOTE: Linux 3.13.0-35-generic amd64/Oracle Corporation 1.9.0-ea (64-bit)/cpus=8,threads=1,free=330974048,total=472383488
[junit4] 2> NOTE: All tests run in this JVM: [ModifyConfFileTest, TestQueryUtils, TestLFUCache, DistributedIntervalFacetingTest, CursorMarkTest, TestReversedWildcardFilterFactory, RequestHandlersTest, SharedFSAutoReplicaFailoverUtilsTest, CircularListTest, CoreMergeIndexesAdminHandlerTest, DistributedFacetPivotLongTailTest, TestCSVLoader, QueryElevationComponentTest, BlockCacheTest, HdfsUnloadDistributedZkTest, LukeRequestHandlerTest, CustomCollectionTest, OverriddenZkACLAndCredentialsProvidersTest, CoreAdminCreateDiscoverTest, TestIndexSearcher, TestShortCircuitedRequests, TestPseudoReturnFields, LeaderElectionIntegrationTest, TestIndexingPerformance, TestGroupingSearch, TestSchemaSimilarityResource, TestBM25SimilarityFactory, TestDistributedGrouping, BJQParserTest, TestBinaryField, DistanceFunctionTest, UUIDUpdateProcessorFallbackTest, RankQueryTest, MergeStrategyTest, CursorPagingTest, DeleteInactiveReplicaTest, StressHdfsTest, SolrTestCaseJ4Test, HdfsSyncSliceTest, ChaosMonkeySafeLeaderTest, OpenCloseCoreStressTest, TestQuerySenderNoQuery, TestMissingGroups, QueryParsingTest, DistribCursorPagingTest, FieldAnalysisRequestHandlerTest, TestBlendedInfixSuggestions, DirectUpdateHandlerOptimizeTest, TestSchemaResource, PolyFieldTest, HdfsBasicDistributedZkTest, CSVRequestHandlerTest, SoftAutoCommitTest, DirectSolrConnectionTest, DocValuesTest, AsyncMigrateRouteKeyTest, SchemaVersionSpecificBehaviorTest, RemoteQueryErrorTest, TestSolrQueryParserResource, TestNonNRTOpen, TestExceedMaxTermLength, DistributedDebugComponentTest, TestCSVResponseWriter, TestOrdValues, TestExpandComponent, HighlighterMaxOffsetTest, SolrInfoMBeanTest, SortByFunctionTest, TestSearcherReuse, ShardSplitTest, TestMultiCoreConfBootstrap, TestBadConfig, TestPerFieldSimilarity, DateFieldTest, StatsComponentTest, LoggingHandlerTest, BinaryUpdateRequestHandlerTest, PreAnalyzedFieldTest, ClusterStateTest, HttpPartitionTest, SolrPluginUtilsTest, FullSolrCloudDistribCmdsTest, AddSchemaFieldsUpdateProcessorFactoryTest, RAMDirectoryFactoryTest, ChangedSchemaMergeTest, TestZkChroot, TestJmxMonitoredMap, PreAnalyzedUpdateProcessorTest, TestCopyFieldCollectionResource, LegacyHTMLStripCharFilterTest, TestMergePolicyConfig, TestUtils, PrimUtilsTest, SliceStateTest, SimplePostToolTest, TestRealTimeGet, TestFieldSortValues, TestCloudManagedSchemaConcurrent, BasicDistributedZk2Test, DistributedFacetPivotSmallTest, TestSolrQueryParser, TestManagedResource, CollectionsAPIDistributedZkTest, BasicZkTest, RecoveryZkTest, ZkSolrClientTest, TestRandomDVFaceting, TestDistributedSearch, TermVectorComponentDistributedTest, HardAutoCommitTest, DistributedTermsComponentTest, PeerSyncTest, TestSort, TestFunctionQuery, BasicFunctionalityTest, TestLazyCores, CurrencyFieldOpenExchangeTest, DistributedQueryElevationComponentTest, WordBreakSolrSpellCheckerTest, SolrCoreCheckLockOnStartupTest, TestUpdate, TestAtomicUpdateErrorCases, TestWordDelimiterFilterFactory, QueryEqualityTest, XsltUpdateRequestHandlerTest, DebugComponentTest, CacheHeaderTest, FileBasedSpellCheckerTest, XmlUpdateRequestHandlerTest, PathHierarchyTokenizerFactoryTest, TermVectorComponentTest, FastVectorHighlighterTest, RegexBoostProcessorTest, ReturnFieldsTest, JSONWriterTest, UniqFieldsUpdateProcessorFactoryTest, SearchHandlerTest, SOLR749Test, UpdateParamsTest, CopyFieldTest, SolrIndexConfigTest, MultiTermTest, TestDocSet, NumericFieldsTest, TestElisionMultitermQuery, TestFuzzyAnalyzedSuggestions, TestPostingsSolrHighlighter, TestPhraseSuggestions, SpellPossibilityIteratorTest, TestCharFilters, SynonymTokenizerTest, TestSweetSpotSimilarityFactory, TestDFRSimilarityFactory, TestIBSimilarityFactory, TimeZoneUtilsTest, ScriptEngineTest, DateMathParserTest, ZkNodePropsTest, FileUtilsTest, TestDistributedMissingSort, AssignTest, DeleteLastCustomShardedReplicaTest]
[junit4] Completed on J1 in 131.34s, 1 test, 1 error <<< FAILURES!
[...truncated 245 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:471: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:60: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/extra-targets.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/lucene/common-build.xml:1358: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/lucene/common-build.xml:961: There were test failures: 429 suites, 1772 tests, 1 error, 45 ignored (23 assumptions)
Total time: 91 minutes 43 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.9.0-ea-b28 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any