Build: http://jenkins.thetaphi.de/job/Lucene-Solr-5.x-Linux/11299/ Java: 32bit/jdk1.8.0_40-ea-b09 -server -XX:+UseG1GC
2 tests failed. REGRESSION: org.apache.solr.cloud.BasicDistributedZkTest.testDistribSearch Error Message: commitWithin did not work on node: http://127.0.0.1:54841/u/v/collection1 expected:<68> but was:<67> Stack Trace: java.lang.AssertionError: commitWithin did not work on node: http://127.0.0.1:54841/u/v/collection1 expected:<68> but was:<67> at __randomizedtesting.SeedInfo.seed([73DA5519F1297C4D:F23CDB0186761C71]: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:345) at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869) 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:497) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836) at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738) at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at java.lang.Thread.run(Thread.java:745) REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch Error Message: expected:<0> but was:<1> Stack Trace: java.lang.AssertionError: expected:<0> but was:<1> at __randomizedtesting.SeedInfo.seed([73DA5519F1297C4D:F23CDB0186761C71]: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.junit.Assert.assertEquals(Assert.java:456) at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:153) at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869) at sun.reflect.GeneratedMethodAccessor48.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836) at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738) at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at java.lang.Thread.run(Thread.java:745) Build Log: [...truncated 11363 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-73DA5519F1297C4D-001/init-core-data-001 [junit4] 2> 825194 T2291 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /u/v [junit4] 2> 825196 T2291 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch [junit4] 2> 825197 T2291 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 825197 T2292 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 825297 T2291 oasc.ZkTestServer.run start zk server on port:47849 [junit4] 2> 825298 T2291 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 825299 T2291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 825302 T2298 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11ecbb1 name:ZooKeeperConnection Watcher:127.0.0.1:47849 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 825302 T2291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 825302 T2291 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 825303 T2291 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 825305 T2291 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 825313 T2291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 825318 T2300 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@168680a name:ZooKeeperConnection Watcher:127.0.0.1:47849/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 825319 T2291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 825319 T2291 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 825319 T2291 oascc.SolrZkClient.makePath makePath: /collections/collection1 [junit4] 2> 825321 T2291 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards [junit4] 2> 825323 T2291 oascc.SolrZkClient.makePath makePath: /collections/control_collection [junit4] 2> 825324 T2291 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards [junit4] 2> 825325 T2291 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> 825326 T2291 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml [junit4] 2> 825328 T2291 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> 825329 T2291 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml [junit4] 2> 825330 T2291 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> 825331 T2291 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 825332 T2291 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> 825333 T2291 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt [junit4] 2> 825334 T2291 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> 825335 T2291 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt [junit4] 2> 825336 T2291 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> 825337 T2291 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml [junit4] 2> 825338 T2291 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> 825339 T2291 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml [junit4] 2> 825340 T2291 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> 825341 T2291 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json [junit4] 2> 825342 T2291 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> 825343 T2291 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 825344 T2291 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> 825345 T2291 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt [junit4] 2> 825346 T2291 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> 825346 T2291 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt [junit4] 2> 825703 T2291 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 825820 T2291 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:48989 [junit4] 2> 825821 T2291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 825822 T2291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 825822 T2291 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-73DA5519F1297C4D-001/tempDir-002 [junit4] 2> 825823 T2291 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-73DA5519F1297C4D-001/tempDir-002/' [junit4] 2> 825839 T2291 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-73DA5519F1297C4D-001/tempDir-002/solr.xml [junit4] 2> 825850 T2291 oasc.CoreContainer.<init> New CoreContainer 29309303 [junit4] 2> 825851 T2291 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-73DA5519F1297C4D-001/tempDir-002/] [junit4] 2> 825851 T2291 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 825852 T2291 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 825852 T2291 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 825853 T2291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 825853 T2291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 825853 T2291 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 825854 T2291 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 825854 T2291 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 825855 T2291 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 825855 T2291 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 825856 T2291 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 825856 T2291 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 825857 T2291 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 825857 T2291 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 825858 T2291 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47849/solr [junit4] 2> 825858 T2291 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 825859 T2291 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 825859 T2291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 825861 T2311 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@81bcbf name:ZooKeeperConnection Watcher:127.0.0.1:47849 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 825862 T2291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 825862 T2291 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 825864 T2291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 825865 T2313 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b3705f name:ZooKeeperConnection Watcher:127.0.0.1:47849/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 825865 T2291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 825867 T2291 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 825868 T2291 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 825869 T2291 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 825871 T2291 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 825872 T2291 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 825874 T2291 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 825874 T2291 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48989_u%2Fv [junit4] 2> 825875 T2291 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48989_u%2Fv [junit4] 2> 825876 T2291 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 825877 T2291 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 825879 T2291 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 825882 T2291 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48989_u%2Fv [junit4] 2> 825883 T2291 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 825884 T2291 oasc.Overseer.start Overseer (id=92626964245839875-127.0.0.1:48989_u%2Fv-n_0000000000) starting [junit4] 2> 825886 T2291 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 825891 T2291 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 825917 T2315 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 825917 T2314 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 825921 T2291 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 825923 T2291 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 825925 T2291 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 825929 T2317 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection [junit4] 2> 825929 T2317 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 825930 T2317 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 825953 T2318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 825957 T2314 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:48989/u/v", [junit4] 2> "node_name":"127.0.0.1:48989_u%2Fv", [junit4] 2> "numShards":"1", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"control_collection", [junit4] 2> "operation":"state"} [junit4] 2> 825957 T2314 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1] [junit4] 2> 825957 T2314 oasc.Overseer$ClusterStateUpdater.createCollection state version control_collection 1 [junit4] 2> 825958 T2314 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 825959 T2318 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> 826931 T2317 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 826931 T2317 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection [junit4] 2> 826931 T2317 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 826932 T2317 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection [junit4] 2> 826932 T2317 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 826932 T2317 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-73DA5519F1297C4D-001/tempDir-002/collection1/' [junit4] 2> 826933 T2317 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-73DA5519F1297C4D-001/tempDir-002/collection1/lib/.svn/' to classloader [junit4] 2> 826933 T2317 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-73DA5519F1297C4D-001/tempDir-002/collection1/lib/classes/' to classloader [junit4] 2> 826933 T2317 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-73DA5519F1297C4D-001/tempDir-002/collection1/lib/README' to classloader [junit4] 2> 826958 T2317 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0 [junit4] 2> 826971 T2317 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 826971 T2317 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml [junit4] 2> 826978 T2317 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 827092 T2317 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 827097 T2317 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 827099 T2317 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 827106 T2317 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 827109 T2317 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 827111 T2317 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 827112 T2317 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 827113 T2317 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 827113 T2317 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 827114 T2317 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 827114 T2317 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 827114 T2317 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection [junit4] 2> 827114 T2317 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 827115 T2317 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-73DA5519F1297C4D-001/tempDir-002/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-73DA5519F1297C4D-001/tempDir-001/control/data/ [junit4] 2> 827115 T2317 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd5ff [junit4] 2> 827116 T2317 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-73DA5519F1297C4D-001/tempDir-001/control/data [junit4] 2> 827116 T2317 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-73DA5519F1297C4D-001/tempDir-001/control/data/index/ [junit4] 2> 827116 T2317 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-73DA5519F1297C4D-001/tempDir-001/control/data/index' doesn't exist. Creating new index... [junit4] 2> 827116 T2317 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-73DA5519F1297C4D-001/tempDir-001/control/data/index [junit4] 2> 827117 T2317 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=23, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=65.9248046875, floorSegmentMB=2.0888671875, forceMergeDeletesPctAllowed=27.070066187390804, segmentsPerTier=22.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 827117 T2317 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-eb1b56)),segFN=segments_1,generation=1} [junit4] 2> 827118 T2317 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 827120 T2317 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 827121 T2317 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 827121 T2317 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 827121 T2317 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 827121 T2317 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 827122 T2317 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 827122 T2317 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 827122 T2317 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 827123 T2317 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 827123 T2317 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 827123 T2317 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 827124 T2317 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 827124 T2317 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 827124 T2317 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 827125 T2317 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 827125 T2317 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 827125 T2317 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 827126 T2317 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 827126 T2317 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 827126 T2317 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 827128 T2317 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 827130 T2317 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 827131 T2317 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 827131 T2317 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 827133 T2317 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 827133 T2317 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 827134 T2317 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=33, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0] [junit4] 2> 827135 T2317 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-eb1b56)),segFN=segments_1,generation=1} [junit4] 2> 827135 T2317 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 827135 T2317 oass.SolrIndexSearcher.<init> Opening Searcher@14b64a[collection1] main [junit4] 2> 827135 T2317 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection [junit4] 2> 827136 T2317 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 827136 T2317 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 827140 T2317 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 827141 T2317 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 827141 T2317 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 827142 T2317 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json [junit4] 2> 827142 T2317 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 827143 T2317 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json [junit4] 2> 827146 T2317 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json [junit4] 2> 827146 T2317 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 827146 T2317 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 827148 T2319 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14b64a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 827150 T2317 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 827150 T2322 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48989/u/v collection:control_collection shard:shard1 [junit4] 2> 827151 T2291 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0 [junit4] 2> 827151 T2291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 827152 T2291 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 827153 T2322 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election [junit4] 2> 827156 T2322 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1 [junit4] 2> 827157 T2318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 827158 T2322 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 827158 T2322 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C592 name=collection1 org.apache.solr.core.SolrCore@e484d9 url=http://127.0.0.1:48989/u/v/collection1 node=127.0.0.1:48989_u%2Fv C592_STATE=coll:control_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:48989/u/v, node_name=127.0.0.1:48989_u%2Fv, state=down} [junit4] 2> 827158 T2322 C592 P48989 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48989/u/v/collection1/ [junit4] 2> 827159 T2322 C592 P48989 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 827159 T2322 C592 P48989 oasc.SyncStrategy.syncToMe http://127.0.0.1:48989/u/v/collection1/ has no replicas [junit4] 2> 827159 T2322 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48989/u/v/collection1/ shard1 [junit4] 2> 827159 T2322 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1 [junit4] 2> 827163 T2318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 827165 T2291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 827175 T2324 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@134f464 name:ZooKeeperConnection Watcher:127.0.0.1:47849/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 827175 T2291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 827176 T2291 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 827177 T2291 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 827179 T2291 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 827269 T2318 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> 827274 T2325 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> 827314 T2322 oasc.ZkController.register We are http://127.0.0.1:48989/u/v/collection1/ and leader is http://127.0.0.1:48989/u/v/collection1/ [junit4] 2> 827314 T2322 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48989/u/v [junit4] 2> 827314 T2322 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 827315 T2322 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection [junit4] 2> 827315 T2322 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 827316 T2318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 827318 T2314 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:48989/u/v", [junit4] 2> "node_name":"127.0.0.1:48989_u%2Fv", [junit4] 2> "numShards":"2", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"control_collection", [junit4] 2> "operation":"state"} [junit4] 2> 827420 T2318 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> 827423 T2325 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> 827573 T2291 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1 [junit4] 2> 827574 T2291 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 827576 T2291 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54841 [junit4] 2> 827577 T2291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 827577 T2291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 827578 T2291 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-73DA5519F1297C4D-001/tempDir-003 [junit4] 2> 827578 T2291 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-73DA5519F1297C4D-001/tempDir-003/' [junit4] 2> 827595 T2291 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-73DA5519F1297C4D-001/tempDir-003/solr.xml [junit4] 2> 827605 T2291 oasc.CoreContainer.<init> New CoreContainer 32992092 [junit4] 2> 827606 T2291 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-73DA5519F1297C4D-001/tempDir-003/] [junit4] 2> 827606 T2291 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 827607 T2291 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 827607 T2291 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 827608 T2291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 827608 T2291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 827609 T2291 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 827609 T2291 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 827609 T2291 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 827610 T2291 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 827610 T2291 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 827611 T2291 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 827611 T2291 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 827612 T2291 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 827612 T2291 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 827613 T2291 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47849/solr [junit4] 2> 827613 T2291 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 827614 T2291 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 827670 T2291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 827671 T2336 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9eb648 name:ZooKeeperConnection Watcher:127.0.0.1:47849 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 827672 T2291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 827672 T2291 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 827675 T2291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 827676 T2338 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10c4f0b name:ZooKeeperConnection Watcher:127.0.0.1:47849/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 827677 T2291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 827680 T2291 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 828683 T2291 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54841_u%2Fv [junit4] 2> 828684 T2291 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54841_u%2Fv [junit4] 2> 828688 T2291 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 828691 T2340 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1 [junit4] 2> 828692 T2340 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 828692 T2340 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 828697 T2318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 828699 T2314 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:54841/u/v", [junit4] 2> "node_name":"127.0.0.1:54841_u%2Fv", [junit4] 2> "numShards":"2", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 828699 T2314 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2] [junit4] 2> 828699 T2314 oasc.Overseer$ClusterStateUpdater.createCollection state version collection1 1 [junit4] 2> 828699 T2314 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2 [junit4] 2> 828803 T2318 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> 828804 T2325 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> 828806 T2339 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> 829693 T2340 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 829693 T2340 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1 [junit4] 2> 829693 T2340 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 829694 T2340 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 829694 T2340 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 829694 T2340 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-73DA5519F1297C4D-001/tempDir-003/collection1/' [junit4] 2> 829695 T2340 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-73DA5519F1297C4D-001/tempDir-003/collection1/lib/.svn/' to classloader [junit4] 2> 829696 T2340 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-73DA5519F1297C4D-001/tempDir-003/collection1/lib/classes/' to classloader [junit4] 2> 829696 T2340 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-73DA5519F1297C4D-001/tempDir-003/collection1/lib/README' to classloader [junit4] 2> 829722 T2340 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0 [junit4] 2> 829734 T2340 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 829735 T2340 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml [junit4] 2> 829741 T2340 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 829852 T2340 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 829857 T2340 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 829862 T2340 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 829873 T2340 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 829876 T2340 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 829879 T2340 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 829880 T2340 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 829881 T2340 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 829881 T2340 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 829882 T2340 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 829883 T2340 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 829883 T2340 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 829883 T2340 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 829883 T2340 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-73DA5519F1297C4D-001/tempDir-003/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-73DA5519F1297C4D-001/tempDir-001/jetty1/ [junit4] 2> 829884 T2340 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd5ff [junit4] 2> 829885 T2340 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-73DA5519F1297C4D-001/tempDir-001/jetty1 [junit4] 2> 829885 T2340 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-73DA5519F1297C4D-001/tempDir-001/jetty1/index/ [junit4] 2> 829885 T2340 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-73DA5519F1297C4D-001/tempDir-001/jetty1/index' doesn't exist. Creating new index... [junit4] 2> 829886 T2340 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-73DA5519F1297C4D-001/tempDir-001/jetty1/index [junit4] 2> 829886 T2340 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=23, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=65.9248046875, floorSegmentMB=2.0888671875, forceMergeDeletesPctAllowed=27.070066187390804, segmentsPerTier=22.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 829887 T2340 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-947074)),segFN=segments_1,generation=1} [junit4] 2> 829887 T2340 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 829891 T2340 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 829891 T2340 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 829892 T2340 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 829892 T2340 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 829892 T2340 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 829892 T2340 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 829893 T2340 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 829893 T2340 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 829893 T2340 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 829894 T2340 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 829894 T2340 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 829895 T2340 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 829895 T2340 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 829896 T2340 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 829896 T2340 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 829896 T2340 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 829897 T2340 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 829897 T2340 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 829897 T2340 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 829898 T2340 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 829900 T2340 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 829902 T2340 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 829903 T2340 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 829904 T2340 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 829922 T2340 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 829923 T2340 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 829923 T2340 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=33, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0] [junit4] 2> 829924 T2340 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-947074)),segFN=segments_1,generation=1} [junit4] 2> 829924 T2340 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 829924 T2340 oass.SolrIndexSearcher.<init> Opening Searcher@1394056[collection1] main [junit4] 2> 829925 T2340 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 829926 T2340 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 829926 T2340 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 829927 T2340 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 829927 T2340 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 829927 T2340 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 829928 T2340 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json [junit4] 2> 829928 T2340 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 829929 T2340 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed [junit4] 2> 829929 T2340 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 829932 T2341 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1394056[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 829935 T2340 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 829936 T2344 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54841/u/v collection:collection1 shard:shard2 [junit4] 2> 829936 T2291 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0 [junit4] 2> 829937 T2344 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 829937 T2291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 829955 T2344 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2 [junit4] 2> 829957 T2318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 829957 T2344 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 829958 T2344 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C593 name=collection1 org.apache.solr.core.SolrCore@5f4dd url=http://127.0.0.1:54841/u/v/collection1 node=127.0.0.1:54841_u%2Fv C593_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:54841/u/v, node_name=127.0.0.1:54841_u%2Fv, state=down} [junit4] 2> 829959 T2344 C593 P54841 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54841/u/v/collection1/ [junit4] 2> 829960 T2344 C593 P54841 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 829960 T2344 C593 P54841 oasc.SyncStrategy.syncToMe http://127.0.0.1:54841/u/v/collection1/ has no replicas [junit4] 2> 829960 T2344 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54841/u/v/collection1/ shard2 [junit4] 2> 829960 T2344 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2 [junit4] 2> 829963 T2318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 830066 T2325 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> 830066 T2318 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> 830066 T2339 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> 830115 T2344 oasc.ZkController.register We are http://127.0.0.1:54841/u/v/collection1/ and leader is http://127.0.0.1:54841/u/v/collection1/ [junit4] 2> 830115 T2344 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54841/u/v [junit4] 2> 830116 T2344 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 830116 T2344 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1 [junit4] 2> 830116 T2344 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 830117 T2318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 830119 T2314 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:54841/u/v", [junit4] 2> "node_name":"127.0.0.1:54841_u%2Fv", [junit4] 2> "numShards":"2", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard2", [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 830222 T2325 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> 830222 T2339 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> 830223 T2318 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> 830327 T2291 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2 [junit4] 2> 830328 T2291 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 830337 T2291 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44238 [junit4] 2> 830338 T2291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 830339 T2291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 830339 T2291 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-73DA5519F1297C4D-001/tempDir-004 [junit4] 2> 830339 T2291 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-73DA5519F1297C4D-001/tempDir-004/' [junit4] 2> 830358 T2291 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-73DA5519F1297C4D-001/tempDir-004/solr.xml [junit4] 2> 830370 T2291 oasc.CoreContainer.<init> New CoreContainer 24383955 [junit4] 2> 830371 T2291 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-73DA5519F1297C4D-001/tempDir-004/] [junit4] 2> 830372 T2291 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 830372 T2291 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 830372 T2291 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 830373 T2291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 830373 T2291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 830374 T2291 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 830374 T2291 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 830374 T2291 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 830375 T2291 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 830375 T2291 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 830376 T2291 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 830376 T2291 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 830377 T2291 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 830377 T2291 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 830378 T2291 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47849/solr [junit4] 2> 830378 T2291 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 830379 T2291 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 830380 T2291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 830381 T2355 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1560d2d name:ZooKeeperConnection Watcher:127.0.0.1:47849 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 830382 T2291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 830383 T2291 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 830385 T2291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 830387 T2357 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17fb48f name:ZooKeeperConnection Watcher:127.0.0.1:47849/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 830388 T2291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 830392 T2291 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 831402 T2291 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44238_u%2Fv [junit4] 2> 831403 T2291 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44238_u%2Fv [junit4] 2> 831407 T2291 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 831413 T2359 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1 [junit4] 2> 831413 T2359 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 831414 T2318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 831416 T2314 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:44238/u/v", [junit4] 2> "node_name":"127.0.0.1:44238_u%2Fv", [junit4] 2> "numShards":"2", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 831416 T2314 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2 [junit4] 2> 831416 T2314 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 831417 T2359 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 831519 T2325 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> 831519 T2339 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> 831520 T2358 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> 831520 T2318 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> 832418 T2359 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 832418 T2359 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1 [junit4] 2> 832419 T2359 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 832419 T2359 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 832419 T2359 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 832420 T2359 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-73DA5519F1297C4D-001/tempDir-004/collection1/' [junit4] 2> 832420 T2359 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-73DA5519F1297C4D-001/tempDir-004/collection1/lib/.svn/' to classloader [junit4] 2> 832421 T2359 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-73DA5519F1297C4D-001/tempDir-004/collection1/lib/classes/' to classloader [junit4] 2> 832421 T2359 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-73DA5519F1297C4D-001/tempDir-004/collection1/lib/README' to classloader [junit4] 2> 832449 T2359 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0 [junit4] 2> 832511 T2359 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 832512 T2359 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml [junit4] 2> 832518 T2359 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 832624 T2359 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 832629 T2359 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 832631 T2359 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 832639 T2359 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 832642 T2359 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 832644 T2359 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 832645 T2359 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 832646 T2359 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 832646 T2359 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 832647 T2359 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 832647 T2359 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 832647 T2359 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 832647 T2359 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 832648 T2359 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-73DA5519F1297C4D-001/tempDir-004/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-73DA5519F1297C4D-001/tempDir-001/jetty2/ [junit4] 2> 832648 T2359 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd5ff [junit4] 2> 832649 T2359 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-73DA5519F1297C4D-001/tempDir-001/jetty2 [junit4] 2> 832649 T2359 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-73DA5519F1297C4D-001/tempDir-001/jetty2/index/ [junit4] 2> 832649 T2359 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-73DA5519F1297C4D-001/tempDir-001/jetty2/index' doesn't exist. Creating new index... [junit4] 2> 832650 T2359 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-73DA5519F1297C4D-001/tempDir-001/jetty2/index [junit4] 2> 832650 T2359 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=23, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=65.9248046875, floorSegmentMB=2.0888671875, forceMergeDeletesPctAllowed=27.070066187390804, segmentsPerTier=22.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 832651 T2359 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1fa2b9b)),segFN=segments_1,generation=1} [junit4] 2> 832652 T2359 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 832655 T2359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 832655 T2359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 832656 T2359 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 832656 T2359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 832656 T2359 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 832656 T2359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 832657 T2359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 832657 T2359 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 832657 T2359 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 832658 T2359 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 832658 T2359 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 832659 T2359 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 832659 T2359 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 832660 T2359 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 832660 T2359 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 832660 T2359 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 832661 T2359 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 832661 T2359 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 832661 T2359 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 832662 T2359 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 832664 T2359 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 832665 T2359 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 832666 T2359 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 832667 T2359 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 832669 T2359 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 832669 T2359 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 832670 T2359 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=33, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0] [junit4] 2> 832670 T2359 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1fa2b9b)),segFN=segments_1,generation=1} [junit4] 2> 832671 T2359 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 832671 T2359 oass.SolrIndexSearcher.<init> Opening Searcher@1bec8c5[collection1] main [junit4] 2> 832671 T2359 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 832672 T2359 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 832672 T2359 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 832672 T2359 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 832673 T2359 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 832673 T2359 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 832674 T2359 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json [junit4] 2> 832674 T2359 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 832674 T2359 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed [junit4] 2> 832674 T2359 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 832679 T2359 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 832687 T2360 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1bec8c5[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 832697 T2363 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44238/u/v collection:collection1 shard:shard1 [junit4] 2> 832697 T2291 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J0 [junit4] 2> 832697 T2291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 832709 T2363 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 832722 T2363 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1 [junit4] 2> 832723 T2318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 832723 T2363 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 832723 T2363 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C594 name=collection1 org.apache.solr.core.SolrCore@9dba1e url=http://127.0.0.1:44238/u/v/collection1 node=127.0.0.1:44238_u%2Fv C594_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:44238/u/v, node_name=127.0.0.1:44238_u%2Fv, state=down} [junit4] 2> 832724 T2363 C594 P44238 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44238/u/v/collection1/ [junit4] 2> 832724 T2363 C594 P44238 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 832724 T2363 C594 P44238 oasc.SyncStrategy.syncToMe http://127.0.0.1:44238/u/v/collection1/ has no replicas [junit4] 2> 832724 T2363 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44238/u/v/collection1/ shard1 [junit4] 2> 832724 T2363 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 832729 T2318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 832730 T2325 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> 832730 T2339 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> 832731 T2318 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> 832731 T2358 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> 832778 T2363 oasc.ZkController.register We are http://127.0.0.1:44238/u/v/collection1/ and leader is http://127.0.0.1:44238/u/v/collection1/ [junit4] 2> 832778 T2363 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44238/u/v [junit4] 2> 832778 T2363 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 832778 T2363 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1 [junit4] 2> 832779 T2363 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 832780 T2318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 832783 T2314 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:44238/u/v", [junit4] 2> "node_name":"127.0.0.1:44238_u%2Fv", [junit4] 2> "numShards":"2", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 832885 T2325 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> 832885 T2339 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> 832886 T2358 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> 832885 T2318 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> 833147 T2291 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3 [junit4] 2> 833148 T2291 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 833151 T2291 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39177 [junit4] 2> 833152 T2291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 833152 T2291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 833153 T2291 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-73DA5519F1297C4D-001/tempDir-005 [junit4] 2> 833153 T2291 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-73DA5519F1297C4D-001/tempDir-005/' [junit4] 2> 833170 T2291 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-73DA5519F1297C4D-001/tempDir-005/solr.xml [junit4] 2> 833181 T2291 oasc.CoreContainer.<init> New CoreContainer 10463054 [junit4] 2> 833182 T2291 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-73DA5519F1297C4D-001/tempDir-005/] [jun [...truncated too long message...] cumulative_adds=298,cumulative_deletesById=122,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=10818,transaction_logs_total_number=1} [junit4] 2> 1183776 T3703 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState [junit4] 2> 1183776 T3703 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter [junit4] 2> 1183777 T3703 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser [junit4] 2> 1183776 T3792 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"https://127.0.0.1:33702", [junit4] 2> "node_name":"127.0.0.1:33702_", [junit4] 2> "state":"down", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 1183778 T3703 C717 P33702 oasu.DirectUpdateHandler2.closeWriter Committing on IndexWriter close. [junit4] 2> 1183780 T3753 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> C717_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=https://127.0.0.1:33702, node_name=127.0.0.1:33702_, state=down, leader=true} [junit4] 2> 1183815 T3703 C717 P33702 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2 [junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73DA5519F1297C4D-001/tempDir-001/jetty1/index,segFN=segments_2,generation=2} [junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73DA5519F1297C4D-001/tempDir-001/jetty1/index,segFN=segments_3,generation=3} [junit4] 2> 1183816 T3703 C717 P33702 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3 [junit4] 2> 1183820 T3703 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request. [junit4] 2> 1183820 T3703 oasc.CachingDirectoryFactory.close Closing StandardDirectoryFactory - 2 directories currently being tracked [junit4] 2> 1183821 T3703 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73DA5519F1297C4D-001/tempDir-001/jetty1 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73DA5519F1297C4D-001/tempDir-001/jetty1;done=false>>] [junit4] 2> 1183821 T3703 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73DA5519F1297C4D-001/tempDir-001/jetty1 [junit4] 2> 1183822 T3703 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73DA5519F1297C4D-001/tempDir-001/jetty1/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73DA5519F1297C4D-001/tempDir-001/jetty1/index;done=false>>] [junit4] 2> 1183822 T3703 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73DA5519F1297C4D-001/tempDir-001/jetty1/index [junit4] 2> 1183824 T3703 oasc.Overseer.close Overseer (id=92626986228908039-127.0.0.1:33702_-n_0000000001) closing [junit4] 2> 1183824 T3792 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:33702_ [junit4] 2> 1185327 T3753 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK [junit4] 2> 1185352 T3703 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null} [junit4] 2> 1190340 T3703 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 57856 [junit4] 2> 1190341 T3703 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch [junit4] 2> 1190342 T3703 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:43285 43285 [junit4] 2> 1191044 T3704 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:43285 43285 [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.method=testDistribSearch -Dtests.seed=73DA5519F1297C4D -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar_AE -Dtests.timezone=America/Argentina/ComodRivadavia -Dtests.file.encoding=ISO-8859-1 [junit4] FAILURE 30.3s J1 | ChaosMonkeySafeLeaderTest.testDistribSearch <<< [junit4] > Throwable #1: java.lang.AssertionError: expected:<0> but was:<1> [junit4] > at __randomizedtesting.SeedInfo.seed([73DA5519F1297C4D:F23CDB0186761C71]:0) [junit4] > at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:153) [junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1191063 T3703 oas.SolrTestCaseJ4.deleteCore ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-73DA5519F1297C4D-001 [junit4] 2> NOTE: test params are: codec=Asserting(Lucene50): {rnd_b=PostingsFormat(name=Lucene41VarGapFixedInterval), _version_=PostingsFormat(name=Lucene41VarGapFixedInterval), a_t=PostingsFormat(name=Lucene41VarGapFixedInterval), a_i=PostingsFormat(name=Lucene41VarGapFixedInterval), id=PostingsFormat(name=Lucene41VarGapFixedInterval)}, docValues:{}, sim=DefaultSimilarity, locale=ar_AE, timezone=America/Argentina/ComodRivadavia [junit4] 2> NOTE: Linux 3.13.0-37-generic i386/Oracle Corporation 1.8.0_40-ea (32-bit)/cpus=8,threads=1,free=244891640,total=536870912 [junit4] 2> NOTE: All tests run in this JVM: [SharedFSAutoReplicaFailoverUtilsTest, HdfsUnloadDistributedZkTest, CSVRequestHandlerTest, FullSolrCloudDistribCmdsTest, TestExceedMaxTermLength, CoreMergeIndexesAdminHandlerTest, FieldAnalysisRequestHandlerTest, StatsComponentTest, DefaultValueUpdateProcessorTest, UUIDUpdateProcessorFallbackTest, SolrInfoMBeanTest, PreAnalyzedFieldTest, CachingDirectoryFactoryTest, AnalyticsQueryTest, SolrRequestParserTest, CloudExitableDirectoryReaderTest, BasicZkTest, DistributedFacetPivotLargeTest, BadCopyFieldTest, TestAtomicUpdateErrorCases, TestPHPSerializedResponseWriter, TestSolrXmlPersistence, TestSolrQueryParserDefaultOperatorResource, TestSchemaResource, OpenCloseCoreStressTest, TestSchemaManager, CoreContainerCoreInitFailuresTest, LoggingHandlerTest, OverseerStatusTest, TestBadConfig, OutputWriterTest, DistributedTermsComponentTest, DocValuesMissingTest, TestBM25SimilarityFactory, RollingRestartTest, TestMultiCoreConfBootstrap, AnalysisErrorHandlingTest, TermVectorComponentTest, BasicDistributedZk2Test, CursorMarkTest, DeleteInactiveReplicaTest, TestRealTimeGet, ShardRoutingCustomTest, RemoteQueryErrorTest, HdfsChaosMonkeySafeLeaderTest, HdfsSyncSliceTest, DeleteReplicaTest, TestFunctionQuery, EnumFieldTest, TestQuerySenderNoQuery, CopyFieldTest, ConvertedLegacyTest, DistributedQueryElevationComponentTest, DistributedExpandComponentTest, TestPhraseSuggestions, CursorPagingTest, SolrCoreTest, TestShardHandlerFactory, SoftAutoCommitTest, RAMDirectoryFactoryTest, CollectionsAPIDistributedZkTest, DirectSolrConnectionTest, CurrencyFieldXmlFileTest, SynonymTokenizerTest, InfoHandlerTest, TestIBSimilarityFactory, BinaryUpdateRequestHandlerTest, SampleTest, ScriptEngineTest, DeleteLastCustomShardedReplicaTest, DateMathParserTest, URLClassifyProcessorTest, ModifyConfFileTest, TestSchemaSimilarityResource, TestPostingsSolrHighlighter, TestRandomFaceting, SolrPluginUtilsTest, AsyncMigrateRouteKeyTest, ChangedSchemaMergeTest, TestBlendedInfixSuggestions, TestRecovery, TestStressLucene, TestMissingGroups, TestLazyCores, TestInitParams, AutoCommitTest, ChaosMonkeySafeLeaderTest] [junit4] Completed on J1 in 30.31s, 1 test, 1 failure <<< FAILURES! [...truncated 813 lines...] BUILD FAILED /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:524: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:472: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:61: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/extra-targets.xml:39: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build.xml:189: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/common-build.xml:496: 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:962: There were test failures: 437 suites, 1785 tests, 2 failures, 43 ignored (21 assumptions) Total time: 111 minutes 23 seconds Build step 'Invoke Ant' marked build as failure [description-setter] Description set: Java: 32bit/jdk1.8.0_40-ea-b09 -server -XX:+UseG1GC Archiving artifacts Recording test results Email was triggered for: Failure - Any Sending email for trigger: Failure - Any
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org