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 [email protected]: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 [email protected]: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 [email protected]: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 [email protected]: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
--------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
