Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/949/
1 tests failed. FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test Error Message: Timeout occured while waiting response from server at: http://127.0.0.1:35395/gc_kb Stack Trace: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:35395/gc_kb at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:588) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230) at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.makeRequest(CollectionsAPIDistributedZkTest.java:382) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testErrorHandling(CollectionsAPIDistributedZkTest.java:459) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test(CollectionsAPIDistributedZkTest.java:169) 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:1764) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921) at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:996) at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:971) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) 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:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367) at java.lang.Thread.run(Thread.java:745) Caused by: java.net.SocketTimeoutException: Read timed out at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:170) at java.net.SocketInputStream.read(SocketInputStream.java:141) at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160) at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84) at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57) at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261) at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283) at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251) at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197) at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272) at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124) at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487) at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:482) ... 47 more Build Log: [...truncated 11456 lines...] [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest [junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/init-core-data-001 [junit4] 2> 689363 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[95CCB031FA6A0FEB]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) [junit4] 2> 689363 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[95CCB031FA6A0FEB]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /gc_kb/ [junit4] 2> 689367 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 689367 INFO (Thread-5812) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 689367 INFO (Thread-5812) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 689467 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.ZkTestServer start zk server on port:56623 [junit4] 2> 689467 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 689468 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 689473 INFO (zkCallback-1449-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@45ae402c name:ZooKeeperConnection Watcher:127.0.0.1:56623 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 689473 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 689473 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 689473 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 689477 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 689477 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 689479 INFO (zkCallback-1450-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@70a06e9b name:ZooKeeperConnection Watcher:127.0.0.1:56623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 689479 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 689479 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 689479 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1 [junit4] 2> 689481 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards [junit4] 2> 689483 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection [junit4] 2> 689484 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards [junit4] 2> 689485 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4] 2> 689486 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml [junit4] 2> 689488 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml [junit4] 2> 689488 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml [junit4] 2> 689491 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 689491 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 689493 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt [junit4] 2> 689494 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt [junit4] 2> 689496 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt [junit4] 2> 689496 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt [junit4] 2> 689498 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml [junit4] 2> 689499 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml [junit4] 2> 689501 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 689501 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml [junit4] 2> 689503 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4] 2> 689503 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json [junit4] 2> 689505 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 689505 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 689507 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 689507 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt [junit4] 2> 689508 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt [junit4] 2> 689509 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt [junit4] 2> 689620 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/cores/collection1 [junit4] 2> 689622 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.e.j.s.Server jetty-9.3.6.v20151106 [junit4] 2> 689624 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@56e40433{/gc_kb,null,AVAILABLE} [junit4] 2> 689626 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.e.j.s.ServerConnector Started ServerConnector@1e420bf3{HTTP/1.1,[http/1.1]}{127.0.0.1:34451} [junit4] 2> 689626 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.e.j.s.Server Started @693041ms [junit4] 2> 689627 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/tempDir-001/control/data, hostContext=/gc_kb, hostPort=34451, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/cores} [junit4] 2> 689627 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@4e0e2f2a [junit4] 2> 689627 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001' [junit4] 2> 689627 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 689627 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI) [junit4] 2> 689627 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 689628 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 689630 INFO (zkCallback-1451-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@5a5b3e98 name:ZooKeeperConnection Watcher:127.0.0.1:56623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 689630 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 689630 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 689631 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 689631 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/solr.xml [junit4] 2> 689637 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/cores [junit4] 2> 689637 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.CoreContainer New CoreContainer 1295363267 [junit4] 2> 689637 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001] [junit4] 2> 689637 WARN (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/lib [junit4] 2> 689637 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false, [junit4] 2> 689639 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 689639 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 689639 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 689639 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:56623/solr [junit4] 2> 689639 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.ZkController zkHost includes chroot [junit4] 2> 689640 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 689640 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 689642 INFO (zkCallback-1454-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@7ec5f83a name:ZooKeeperConnection Watcher:127.0.0.1:56623 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 689643 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 689643 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 689645 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 689650 INFO (zkCallback-1455-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2bc07f6b name:ZooKeeperConnection Watcher:127.0.0.1:56623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 689650 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 689651 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue [junit4] 2> 689653 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work [junit4] 2> 689657 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running [junit4] 2> 689659 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed [junit4] 2> 689660 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure [junit4] 2> 689662 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 689664 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 689665 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 689667 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 689668 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 689669 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 689671 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 689672 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 689673 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 689674 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000 [junit4] 2> 689674 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:34451_gc_kb [junit4] 2> 689674 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 689675 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.Overseer Overseer (id=95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) starting [junit4] 2> 689677 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 689683 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=10000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 689684 INFO (OverseerCollectionConfigSetProcessor-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 689684 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 689685 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34451_gc_kb [junit4] 2> 689686 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:34451_gc_kb [junit4] 2> 689688 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 689688 INFO (zkCallback-1455-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0]) [junit4] 2> 689689 INFO (zkCallback-1455-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 689713 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module. [junit4] 2> 689713 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.CoreContainer No authentication plugin used. [junit4] 2> 689714 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/cores [junit4] 2> 689716 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, configSetProperties=configsetprops.json, collection=control_collection, coreNodeName=, dataDir=data/, shard=} [junit4] 2> 689716 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.CorePropertiesLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/cores/collection1 [junit4] 2> 689716 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.CorePropertiesLocator Found 1 core definitions [junit4] 2> 689717 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1 [junit4] 2> 689717 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:34451_gc_kb ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done [junit4] 2> 689717 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.ZkController publishing state=down [junit4] 2> 689717 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property [junit4] 2> 689719 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:34451/gc_kb";, [junit4] 2> "node_name":"127.0.0.1:34451_gc_kb", [junit4] 2> "numShards":"1", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"control_collection", [junit4] 2> "operation":"state"} current state version: 0 [junit4] 2> 689719 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.ZkController look for our core node name [junit4] 2> 689720 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:34451/gc_kb";, [junit4] 2> "node_name":"127.0.0.1:34451_gc_kb", [junit4] 2> "numShards":"1", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"control_collection", [junit4] 2> "operation":"state"} [junit4] 2> 689720 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.o.ClusterStateMutator building a new cName: control_collection [junit4] 2> 689721 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 689723 INFO (zkCallback-1455-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 690720 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1 [junit4] 2> 690720 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.ZkController Check for collection zkNode:control_collection [junit4] 2> 690721 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.ZkController Collection zkNode exists [junit4] 2> 690721 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.c.ZkStateReader Load collection config from: [/collections/control_collection] [junit4] 2> 690722 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.c.ZkStateReader path=[/collections/control_collection] [configName]=[conf1] specified config exists in ZooKeeper [junit4] 2> 690722 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/cores/collection1' [junit4] 2> 690722 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 690722 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI) [junit4] 2> 690724 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0 [junit4] 2> 690730 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1 [junit4] 2> 690735 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0 [junit4] 2> 690745 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml [junit4] 2> 690752 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 690858 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 690864 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.s.IndexSchema default search field in schema is text [junit4] 2> 690866 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.s.IndexSchema unique key field: id [junit4] 2> 690875 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml [junit4] 2> 690877 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml [junit4] 2> 690879 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json [junit4] 2> 690882 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json [junit4] 2> 690883 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/configs/conf1', cwd=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1 [junit4] 2> 690883 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection [junit4] 2> 690884 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory [junit4] 2> 690884 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/cores/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/cores/collection1/data/] [junit4] 2> 690884 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@73dee3a1 [junit4] 2> 690885 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/cores/collection1/data [junit4] 2> 690885 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/cores/collection1/data/index/ [junit4] 2> 690885 WARN (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index... [junit4] 2> 690885 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/cores/collection1/data/index [junit4] 2> 690886 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@4bf8239c [junit4] 2> 690887 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@125a153c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7ea0d622; maxCacheMB=0.041015625 maxMergeSizeMB=0.5361328125)),segFN=segments_1,generation=1} [junit4] 2> 690887 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1 [junit4] 2> 690887 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/cores/collection1/data/ [junit4] 2> 690887 WARN (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.DirectoryFactory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/control-001/cores/collection1/data/ does not point to a valid data directory; skipping clean-up of old index directories. [junit4] 2> 690892 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib" [junit4] 2> 690892 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe" [junit4] 2> 690892 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 690892 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig" [junit4] 2> 690892 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 690892 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 690892 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 690893 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 690893 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 690893 WARN (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,args = {defaults={a=A,b=B}}} [junit4] 2> 690895 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60 [junit4] 2> 690896 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60 [junit4] 2> 690897 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60 [junit4] 2> 690898 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60 [junit4] 2> 690902 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,/dump,/update/csv,/sql,/update/json/docs,/admin/luke,/export,/admin/segments,/get,/admin/system,/replication,/admin/properties,/config,/stream,/schema,/admin/plugins,/admin/logging,/update/json,/admin/ping,/admin/threads,/update,/admin/file [junit4] 2> 690902 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache [junit4] 2> 690903 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 690903 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 690904 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 690904 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 690904 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=6, maxMergeAtOnceExplicit=3, maxMergedSegmentMB=13.935546875, floorSegmentMB=1.6591796875, forceMergeDeletesPctAllowed=11.342148275565107, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.40785422959103745 [junit4] 2> 690905 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@125a153c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7ea0d622; maxCacheMB=0.041015625 maxMergeSizeMB=0.5361328125)),segFN=segments_1,generation=1} [junit4] 2> 690905 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1 [junit4] 2> 690905 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@69b7caea[collection1] main] [junit4] 2> 690905 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader Load collection config from: [/collections/control_collection] [junit4] 2> 690906 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader path=[/collections/control_collection] [configName]=[conf1] specified config exists in ZooKeeper [junit4] 2> 690907 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 690907 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 690907 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {} [junit4] 2> 690907 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 690907 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage No data found for znode /configs/conf1/_rest_managed.json [junit4] 2> 690908 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 690908 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources [junit4] 2> 690908 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 690909 INFO (searcherExecutor-2324-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@69b7caea[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 690909 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets [junit4] 2> 690909 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version buckets from index [junit4] 2> 690909 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.VersionInfo No terms found for _version_, cannot seed version bucket highest value from index [junit4] 2> 690909 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1527680908157517824 [junit4] 2> 690912 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 2.0ms to seed version buckets with highest version 1527680908157517824 [junit4] 2> 690912 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1 [junit4] 2> 690913 INFO (coreLoadExecutor-2323-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: collection1 [junit4] 2> 690913 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController Register replica - core:collection1 address:http://127.0.0.1:34451/gc_kb collection:control_collection shard:shard1 [junit4] 2> 690914 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leader_elect/shard1/election [junit4] 2> 690918 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.LeaderElector Joined leadership election with path: /collections/control_collection/leader_elect/shard1/election/95480056658919428-core_node1-n_0000000000 [junit4] 2> 690919 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard=shard1 and weAreReplacement=false and leaderVoteWait=180000 [junit4] 2> 690920 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 690921 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 690921 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:34451/gc_kb/collection1/ [junit4] 2> 690921 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"control_collection"} current state version: 1 [junit4] 2> 690921 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 690921 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:34451/gc_kb/collection1/ has no replicas [junit4] 2> 690922 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leaders/shard1 [junit4] 2> 690924 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/control_collection/leaders/shard1/leader after winning as /collections/control_collection/leader_elect/shard1/election/95480056658919428-core_node1-n_0000000000 [junit4] 2> 690927 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:34451/gc_kb/collection1/ shard1 [junit4] 2> 690927 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"control_collection", [junit4] 2> "base_url":"http://127.0.0.1:34451/gc_kb";, [junit4] 2> "core":"collection1", [junit4] 2> "state":"active"} current state version: 1 [junit4] 2> 691031 INFO (zkCallback-1455-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 691078 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController We are http://127.0.0.1:34451/gc_kb/collection1/ and leader is http://127.0.0.1:34451/gc_kb/collection1/ [junit4] 2> 691078 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34451/gc_kb [junit4] 2> 691078 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 691078 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController publishing state=active [junit4] 2> 691078 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property [junit4] 2> 691080 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:34451/gc_kb";, [junit4] 2> "node_name":"127.0.0.1:34451_gc_kb", [junit4] 2> "numShards":"1", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"control_collection", [junit4] 2> "operation":"state"} current state version: 2 [junit4] 2> 691081 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:34451/gc_kb";, [junit4] 2> "node_name":"127.0.0.1:34451_gc_kb", [junit4] 2> "numShards":"1", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"control_collection", [junit4] 2> "operation":"state"} [junit4] 2> 691084 INFO (coreZkRegister-2317-thread-1-processing-n:127.0.0.1:34451_gc_kb x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:34451_gc_kb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (1) [junit4] 2> 691186 INFO (zkCallback-1455-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 691219 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 691221 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 691223 INFO (zkCallback-1457-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2928eaa5 name:ZooKeeperConnection Watcher:127.0.0.1:56623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 691223 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 691223 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 691223 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 691224 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 691226 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 691337 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/shard-1-001/cores/collection1 [junit4] 2> 691338 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/shard-1-001 [junit4] 2> 691338 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.e.j.s.Server jetty-9.3.6.v20151106 [junit4] 2> 691340 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@15f35a20{/gc_kb,null,AVAILABLE} [junit4] 2> 691341 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.e.j.s.ServerConnector Started ServerConnector@55b8be4a{HTTP/1.1,[http/1.1]}{127.0.0.1:35395} [junit4] 2> 691341 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.e.j.s.Server Started @694756ms [junit4] 2> 691341 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/gc_kb, hostPort=35395, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/shard-1-001/cores} [junit4] 2> 691342 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@4e0e2f2a [junit4] 2> 691342 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/shard-1-001' [junit4] 2> 691342 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 691342 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI) [junit4] 2> 691342 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 691343 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 691344 INFO (zkCallback-1458-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1b1cadfb name:ZooKeeperConnection Watcher:127.0.0.1:56623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 691344 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 691345 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 691346 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 691346 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/shard-1-001/solr.xml [junit4] 2> 691352 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/shard-1-001/cores [junit4] 2> 691353 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.CoreContainer New CoreContainer 1974046081 [junit4] 2> 691353 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/shard-1-001] [junit4] 2> 691353 WARN (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/shard-1-001/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/shard-1-001/lib [junit4] 2> 691354 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false, [junit4] 2> 691355 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 691356 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 691356 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 691356 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:56623/solr [junit4] 2> 691356 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.ZkController zkHost includes chroot [junit4] 2> 691356 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 691357 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 691358 INFO (zkCallback-1461-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6e780f1c name:ZooKeeperConnection Watcher:127.0.0.1:56623 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 691359 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 691359 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 691361 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 691365 INFO (zkCallback-1462-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@292a2e9 name:ZooKeeperConnection Watcher:127.0.0.1:56623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 691365 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 691371 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 691372 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 691374 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 691374 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/95480056658919432-127.0.0.1:35395_gc_kb-n_0000000001 [junit4] 2> 691375 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000 to know if I could be the leader [junit4] 2> 691375 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.ZkController Publish node=127.0.0.1:35395_gc_kb as DOWN [junit4] 2> 691377 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"downnode", [junit4] 2> "node_name":"127.0.0.1:35395_gc_kb"} current state version: 3 [junit4] 2> 691377 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:35395_gc_kb [junit4] 2> 691480 INFO (zkCallback-1462-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 691480 INFO (zkCallback-1455-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 691480 INFO (zkCallback-1457-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 692377 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35395_gc_kb [junit4] 2> 692378 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:35395_gc_kb [junit4] 2> 692379 INFO (zkCallback-1462-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 692379 INFO (zkCallback-1455-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 692379 INFO (zkCallback-1457-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 692380 INFO (zkCallback-1462-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 692380 INFO (zkCallback-1457-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 692380 INFO (zkCallback-1455-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 692393 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module. [junit4] 2> 692393 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.CoreContainer No authentication plugin used. [junit4] 2> 692394 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/shard-1-001/cores [junit4] 2> 692395 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, configSetProperties=configsetprops.json, collection=collection1, coreNodeName=, dataDir=data/, shard=} [junit4] 2> 692395 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.CorePropertiesLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/shard-1-001/cores/collection1 [junit4] 2> 692395 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.CorePropertiesLocator Found 1 core definitions [junit4] 2> 692396 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1 [junit4] 2> 692396 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[95CCB031FA6A0FEB]) [n:127.0.0.1:35395_gc_kb ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done [junit4] 2> 692396 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.ZkController publishing state=down [junit4] 2> 692396 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property [junit4] 2> 692398 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.ZkController look for our core node name [junit4] 2> 692398 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:35395/gc_kb";, [junit4] 2> "node_name":"127.0.0.1:35395_gc_kb", [junit4] 2> "numShards":"2", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} current state version: 4 [junit4] 2> 692399 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.o.ReplicaMutator Update state numShards=2 message={ [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:35395/gc_kb";, [junit4] 2> "node_name":"127.0.0.1:35395_gc_kb", [junit4] 2> "numShards":"2", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 692399 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1 [junit4] 2> 692399 INFO (OverseerStateUpdate-95480056658919428-127.0.0.1:34451_gc_kb-n_0000000000) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 692502 INFO (zkCallback-1462-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [2]) [junit4] 2> 692502 INFO (zkCallback-1457-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [2]) [junit4] 2> 692502 INFO (zkCallback-1455-thread-1-processing-n:127.0.0.1:34451_gc_kb) [n:127.0.0.1:34451_gc_kb ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [2]) [junit4] 2> 693399 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1 [junit4] 2> 693399 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.ZkController Check for collection zkNode:collection1 [junit4] 2> 693400 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.ZkController Collection zkNode exists [junit4] 2> 693400 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.c.ZkStateReader Load collection config from: [/collections/collection1] [junit4] 2> 693401 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.c.ZkStateReader path=[/collections/collection1] [configName]=[conf1] specified config exists in ZooKeeper [junit4] 2> 693401 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001/shard-1-001/cores/collection1' [junit4] 2> 693401 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 693401 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI) [junit4] 2> 693404 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0 [junit4] 2> 693412 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1 [junit4] 2> 693438 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0 [junit4] 2> 693448 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml [junit4] 2> 693455 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 693635 INFO (coreLoadExecutor-2334-thread-1-processing-n:127.0.0.1:35395_gc_kb) [n:127.0.0.1:35395_gc_kb c:collection1 x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 693663 INFO (coreLoadExecutor-2334-thre [...truncated too long message...] ion4_2 [junit4] > at __randomizedtesting.SeedInfo.seed([95CCB031FA6A0FEB]:0) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:577) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230) [junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372) [junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1100) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:870) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:806) [junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219) [junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:980)Throwable #6: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=10979, name=collection2, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] [junit4] > Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:37310/gc_kb: collection already exists: awholynewstresscollection_collection2_2 [junit4] > at __randomizedtesting.SeedInfo.seed([95CCB031FA6A0FEB]:0) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:577) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230) [junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372) [junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1100) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:870) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:806) [junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219) [junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1593) [junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1614) [junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:973)Throwable #7: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=10982, name=collection5, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] [junit4] > Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:37310/gc_kb: Could not find collection : awholynewstresscollection_collection5_1 [junit4] > at __randomizedtesting.SeedInfo.seed([95CCB031FA6A0FEB]:0) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:577) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230) [junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372) [junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1100) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:870) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:806) [junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219) [junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:980) [junit4] 2> 1233117 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[95CCB031FA6A0FEB]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_95CCB031FA6A0FEB-001 [junit4] 2> Mar 02, 2016 9:23:07 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s). [junit4] 2> NOTE: test params are: codec=Asserting(Lucene60): {other_tl1=PostingsFormat(name=Asserting), range_facet_l_dv=PostingsFormat(name=LuceneFixedGap), _version_=PostingsFormat(name=Asserting), multiDefault=PostingsFormat(name=LuceneVarGapFixedInterval), a_t=PostingsFormat(name=LuceneVarGapFixedInterval), intDefault=PostingsFormat(name=Asserting), a_i1=PostingsFormat(name=LuceneVarGapFixedInterval), id=PostingsFormat(name=LuceneFixedGap), range_facet_i_dv=PostingsFormat(name=LuceneVarGapFixedInterval), text=FSTOrd50, range_facet_l=PostingsFormat(name=LuceneVarGapFixedInterval), timestamp=PostingsFormat(name=LuceneVarGapFixedInterval)}, docValues:{range_facet_l_dv=DocValuesFormat(name=Lucene54), range_facet_i_dv=DocValuesFormat(name=Direct), timestamp=DocValuesFormat(name=Direct)}, maxPointsInLeafNode=504, maxMBSortInHeap=6.971840847352904, sim=ClassicSimilarity, locale=sq, timezone=America/Jujuy [junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.8.0_66 (64-bit)/cpus=4,threads=1,free=142015208,total=497549312 [junit4] 2> NOTE: All tests run in this JVM: [SchemaVersionSpecificBehaviorTest, TestPartialUpdateDeduplication, ReplicationFactorTest, TestCloudDeleteByQuery, TestExactStatsCache, BlockJoinFacetDistribTest, SpellCheckCollatorTest, DistribJoinFromCollectionTest, TestManagedSynonymFilterFactory, DistributedTermsComponentTest, TestRandomCollapseQParserPlugin, SecurityConfHandlerTest, SuggestComponentTest, MinimalSchemaTest, TestWordDelimiterFilterFactory, TestInitQParser, ExplicitHLLTest, TestDocumentBuilder, TestNoOpRegenerator, SolrIndexConfigTest, DeleteLastCustomShardedReplicaTest, SortSpecParsingTest, TestSchemaNameResource, DistributedMLTComponentTest, MoreLikeThisHandlerTest, TestPerFieldSimilarityClassic, TestClassicSimilarityFactory, SSLMigrationTest, SolrPluginUtilsTest, OpenExchangeRatesOrgProviderTest, TestQuerySenderNoQuery, TestEmbeddedSolrServerConstructors, DistributedIntervalFacetingTest, TestFieldSortValues, CursorMarkTest, TestReqParamsAPI, SpellPossibilityIteratorTest, DocumentBuilderTest, TestSolrQueryParserResource, TestDFRSimilarityFactory, ConjunctionSolrSpellCheckerTest, TestCollapseQParserPlugin, ZkControllerTest, ZkCLITest, TestSimpleTrackingShardHandler, TestConfigOverlay, GraphQueryTest, TestFileDictionaryLookup, BasicFunctionalityTest, DateRangeFieldTest, ChaosMonkeySafeLeaderTest, CoreAdminRequestStatusTest, TestDownShardTolerantSearch, TermsComponentTest, TestCoreContainer, MultiTermTest, TestRawResponseWriter, ParsingFieldUpdateProcessorsTest, TestCloudManagedSchemaConcurrent, TestLeaderInitiatedRecoveryThread, UpdateRequestProcessorFactoryTest, HdfsNNFailoverTest, CollectionsAPIDistributedZkTest] [junit4] Completed [152/582 (1!)] on J1 in 544.04s, 1 test, 1 error <<< FAILURES! [...truncated 1381 lines...] [junit4] JVM J1: stdout was not empty, see: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/temp/junit4-J1-20160302_090231_390.sysout [junit4] >>> JVM J1 emitted unexpected output (verbatim) ---- [junit4] java.lang.OutOfMemoryError: GC overhead limit exceeded [junit4] Dumping heap to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/heapdumps/java_pid13427.hprof ... [junit4] Heap dump file created [685464662 bytes in 4.478 secs] [junit4] <<< JVM J1: EOF ---- [...truncated 16 lines...] BUILD FAILED /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:747: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:684: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:59: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:233: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:524: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1457: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1014: There were test failures: 582 suites (8 ignored), 2355 tests, 1 error, 33 ignored (17 assumptions) [seed: 95CCB031FA6A0FEB] Total time: 225 minutes 45 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts No prior successful build to compare, so performing full copy of 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
