You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2016/05/27 07:30:31 UTC
[JENKINS] Lucene-Solr-NightlyTests-6.0 - Build # 21 - Still Failing
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.0/21/
1 tests failed.
FAILED: org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.test
Error Message:
Captured an uncaught exception in thread: Thread[id=53919, name=collection1, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=53919, name=collection1, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest]
Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:53323, http://127.0.0.1:60769, http://127.0.0.1:49907, http://127.0.0.1:38303, http://127.0.0.1:38744]
at __randomizedtesting.SeedInfo.seed([25DEEA7E1DC473DD]:0)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:1000)
Caused by: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:53323, http://127.0.0.1:60769, http://127.0.0.1:49907, http://127.0.0.1:38303, http://127.0.0.1:38744]
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:352)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1100)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:870)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:806)
at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:997)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:49907: KeeperErrorCode = Session expired for /overseer/collection-queue-work/qnr-
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:577)
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.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325)
... 5 more
Build Log:
[...truncated 12566 lines...]
[junit4] Suite: org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/init-core-data-001
[junit4] 2> 5223634 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false)
[junit4] 2> 5223635 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
[junit4] 1> Formatting using clusterid: testClusterID
[junit4] 2> 5223661 WARN (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
[junit4] 2> 5223676 WARN (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 5223677 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 5223686 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.6.0-tests.jar!/webapps/hdfs to ./temp/Jetty_localhost_41736_hdfs____4pp1pj/webapp
[junit4] 2> 5223766 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
[junit4] 2> 5224051 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:41736
[junit4] 2> 5224099 WARN (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 5224100 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 5224108 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.6.0-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_38958_datanode____.41xb42/webapp
[junit4] 2> 5224185 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
[junit4] 2> 5224493 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:38958
[junit4] 2> 5224575 WARN (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 5224577 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 5224590 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.6.0-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_33926_datanode____1x45dw/webapp
[junit4] 2> 5224622 INFO (IPC Server handler 7 on 38955) [ ] BlockStateChange BLOCK* processReport: from storage DS-85e16d71-55e3-4e5a-85b6-5d8a006e5b41 node DatanodeRegistration(127.0.0.1, datanodeUuid=6b6790ae-c1d8-4b76-b96d-b954b1384e56, infoPort=38958, ipcPort=36015, storageInfo=lv=-56;cid=testClusterID;nsid=1981677780;c=0), blocks: 0, hasStaleStorages: true, processing time: 2 msecs
[junit4] 2> 5224622 INFO (IPC Server handler 7 on 38955) [ ] BlockStateChange BLOCK* processReport: from storage DS-cab43e21-6d45-4cdd-8c4c-9f036a654ac0 node DatanodeRegistration(127.0.0.1, datanodeUuid=6b6790ae-c1d8-4b76-b96d-b954b1384e56, infoPort=38958, ipcPort=36015, storageInfo=lv=-56;cid=testClusterID;nsid=1981677780;c=0), blocks: 0, hasStaleStorages: false, processing time: 0 msecs
[junit4] 2> 5224686 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
[junit4] 2> 5225000 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[25DEEA7E1DC473DD]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:33926
[junit4] 2> 5225069 INFO (IPC Server handler 8 on 38955) [ ] BlockStateChange BLOCK* processReport: from storage DS-9983d900-3cbd-4246-a6ae-056b2f56849b node DatanodeRegistration(127.0.0.1, datanodeUuid=f579fb41-7252-4f5c-8a08-9b12328b8479, infoPort=33926, ipcPort=34612, storageInfo=lv=-56;cid=testClusterID;nsid=1981677780;c=0), blocks: 0, hasStaleStorages: true, processing time: 1 msecs
[junit4] 2> 5225069 INFO (IPC Server handler 8 on 38955) [ ] BlockStateChange BLOCK* processReport: from storage DS-d0e3cd2f-2917-48ab-9bc5-440ddff37a15 node DatanodeRegistration(127.0.0.1, datanodeUuid=f579fb41-7252-4f5c-8a08-9b12328b8479, infoPort=33926, ipcPort=34612, storageInfo=lv=-56;cid=testClusterID;nsid=1981677780;c=0), blocks: 0, hasStaleStorages: false, processing time: 0 msecs
[junit4] 2> 5225163 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 5225163 INFO (Thread-31141) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 5225163 INFO (Thread-31141) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 5225263 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.ZkTestServer start zk server on port:51333
[junit4] 2> 5225263 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 5225264 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 5225266 INFO (zkCallback-5098-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@125a21ca name:ZooKeeperConnection Watcher:127.0.0.1:51333 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5225266 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 5225267 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 5225267 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 5225270 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 5225270 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 5225271 INFO (zkCallback-5099-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@bd2e9fe name:ZooKeeperConnection Watcher:127.0.0.1:51333/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5225271 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 5225271 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 5225271 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1
[junit4] 2> 5225273 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards
[junit4] 2> 5225274 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection
[junit4] 2> 5225275 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards
[junit4] 2> 5225276 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 5225276 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 5225277 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 5225277 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml
[junit4] 2> 5225278 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 5225278 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 5225279 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 5225279 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt
[junit4] 2> 5225280 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 5225280 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt
[junit4] 2> 5225281 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 5225281 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml
[junit4] 2> 5225282 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 5225282 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 5225283 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 5225283 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 5225284 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 5225284 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 5225285 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 5225285 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 5225286 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 5225286 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt
[junit4] 2> 5225345 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/control-001/cores/collection1
[junit4] 2> 5225346 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 5225348 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@76ee5f37{/,null,AVAILABLE}
[junit4] 2> 5225348 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.e.j.s.ServerConnector Started ServerConnector@64f44002{HTTP/1.1,[http/1.1]}{127.0.0.1:38303}
[junit4] 2> 5225348 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.e.j.s.Server Started @5228350ms
[junit4] 2> 5225348 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=hdfs://localhost:38955/hdfs__localhost_38955__x1_jenkins_jenkins-slave_workspace_Lucene-Solr-NightlyTests-6.0_solr_build_solr-core_test_J1_temp_solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001_tempDir-002_control_data, hostContext=/, hostPort=38303, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/control-001/cores}
[junit4] 2> 5225348 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@73d16e93
[junit4] 2> 5225348 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/control-001'
[junit4] 2> 5225348 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 5225348 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 5225349 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 5225349 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 5225350 INFO (zkCallback-5100-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@7ddd4b4d name:ZooKeeperConnection Watcher:127.0.0.1:51333/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5225351 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 5225351 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 5225351 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 5225352 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/control-001/solr.xml
[junit4] 2> 5225356 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/control-001/cores
[junit4] 2> 5225356 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.CoreContainer New CoreContainer 1307910517
[junit4] 2> 5225356 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/control-001]
[junit4] 2> 5225356 WARN (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/control-001/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/control-001/lib
[junit4] 2> 5225356 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] 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> 5225357 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 5225357 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 5225357 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 5225358 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:51333/solr
[junit4] 2> 5225358 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 5225358 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 5225358 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 5225359 INFO (zkCallback-5103-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3c13fce1 name:ZooKeeperConnection Watcher:127.0.0.1:51333 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5225359 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 5225359 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 5225360 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$29/699737714@3b62099f
[junit4] 2> 5225360 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 5225361 INFO (zkCallback-5104-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1cc4cb2 name:ZooKeeperConnection Watcher:127.0.0.1:51333/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5225361 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 5225362 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
[junit4] 2> 5225363 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
[junit4] 2> 5225364 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
[junit4] 2> 5225365 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
[junit4] 2> 5225366 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
[junit4] 2> 5225367 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 5225368 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 5225368 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 5225369 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 5225369 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 5225370 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0)
[junit4] 2> 5225371 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
[junit4] 2> 5225372 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
[junit4] 2> 5225372 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 5225372 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/95966359574478852-127.0.0.1:38303_-n_0000000000
[junit4] 2> 5225373 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:38303_
[junit4] 2> 5225373 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
[junit4] 2> 5225373 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.Overseer Overseer (id=95966359574478852-127.0.0.1:38303_-n_0000000000) starting
[junit4] 2> 5225374 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
[junit4] 2> 5225377 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=10000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 5225377 INFO (OverseerCollectionConfigSetProcessor-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations
[junit4] 2> 5225378 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38303_
[junit4] 2> 5225378 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 5225379 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:38303_
[junit4] 2> 5225380 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0)
[junit4] 2> 5225380 INFO (zkCallback-5104-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ ] 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> 5225380 INFO (zkCallback-5104-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 5225394 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 5225394 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 5225394 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/control-001/cores
[junit4] 2> 5225395 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] 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> 5225395 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.CorePropertiesLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/control-001/cores/collection1
[junit4] 2> 5225395 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions
[junit4] 2> 5225395 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1
[junit4] 2> 5225395 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38303_ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 5225396 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 5225396 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 5225396 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.ZkController Collection control_collection not visible yet, but flagging it so a watch is registered when it becomes visible
[junit4] 2> 5225397 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] 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:38303",
[junit4] 2> "node_name":"127.0.0.1:38303_",
[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> 5225397 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.c.ZkStateReader addZkWatch [control_collection]
[junit4] 2> 5225397 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] 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:38303",
[junit4] 2> "node_name":"127.0.0.1:38303_",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 5225397 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] o.a.s.c.o.ClusterStateMutator building a new cName: control_collection
[junit4] 2> 5225397 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.c.ZkStateReader Deleting data for [control_collection]
[junit4] 2> 5225397 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 5225398 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.ZkController look for our core node name
[junit4] 2> 5225398 INFO (zkCallback-5104-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ ] 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> 5226399 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
[junit4] 2> 5226399 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.ZkController Check for collection zkNode:control_collection
[junit4] 2> 5226399 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.ZkController Collection zkNode exists
[junit4] 2> 5226399 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.c.ZkStateReader Load collection config from: [/collections/control_collection]
[junit4] 2> 5226399 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.c.ZkStateReader path=[/collections/control_collection] [configName]=[conf1] specified config exists in ZooKeeper
[junit4] 2> 5226400 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/control-001/cores/collection1'
[junit4] 2> 5226400 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 5226400 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 5226401 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0
[junit4] 2> 5226404 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 5226421 WARN (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 5226422 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.1
[junit4] 2> 5226428 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
[junit4] 2> 5226432 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 5226499 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 5226503 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.s.IndexSchema default search field in schema is text
[junit4] 2> 5226504 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 5226518 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 5226519 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 5226520 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 5226521 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 5226522 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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-6.0/solr/build/solr-core/test/J1
[junit4] 2> 5226522 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 5226522 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.HdfsDirectoryFactory
[junit4] 2> 5226522 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:38955/solr_hdfs_home
[junit4] 2> 5226522 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 5226522 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/control-001/cores/collection1], dataDir=[hdfs://localhost:38955/solr_hdfs_home/control_collection/core_node1/data/]
[junit4] 2> 5226522 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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@6fc99d50
[junit4] 2> 5226522 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:38955/solr_hdfs_home/control_collection/core_node1/data
[junit4] 2> 5226531 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for hdfs://localhost:38955/solr_hdfs_home/control_collection/core_node1/data
[junit4] 2> 5226531 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=hdfs://localhost:38955/solr_hdfs_home/control_collection/core_node1/data/index/
[junit4] 2> 5226536 WARN (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory 'hdfs:/localhost:38955/solr_hdfs_home/control_collection/core_node1/data/index' doesn't exist. Creating new index...
[junit4] 2> 5226536 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:38955/solr_hdfs_home/control_collection/core_node1/data/index
[junit4] 2> 5226543 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for hdfs://localhost:38955/solr_hdfs_home/control_collection/core_node1/data/index
[junit4] 2> 5226543 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=8, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4017898308290171]
[junit4] 2> 5226555 INFO (IPC Server handler 3 on 38955) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36493 is added to blk_1073741825_1001{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-cab43e21-6d45-4cdd-8c4c-9f036a654ac0:NORMAL:127.0.0.1:54056|RBW], ReplicaUnderConstruction[[DISK]DS-9983d900-3cbd-4246-a6ae-056b2f56849b:NORMAL:127.0.0.1:36493|RBW]]} size 0
[junit4] 2> 5226556 INFO (IPC Server handler 4 on 38955) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:54056 is added to blk_1073741825_1001{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-9983d900-3cbd-4246-a6ae-056b2f56849b:NORMAL:127.0.0.1:36493|RBW], ReplicaUnderConstruction[[DISK]DS-85e16d71-55e3-4e5a-85b6-5d8a006e5b41:NORMAL:127.0.0.1:54056|FINALIZED]]} size 0
[junit4] 2> 5226557 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(HdfsDirectory@hdfs://localhost:38955/solr_hdfs_home/control_collection/core_node1/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5ef182b3; maxCacheMB=192.0 maxMergeSizeMB=16.0),segFN=segments_1,generation=1}
[junit4] 2> 5226557 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 5226558 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:38303_ 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 hdfs://localhost:38955/solr_hdfs_home/control_collection/core_node1/data/
[junit4] 2> 5226559 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 5226560 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
[junit4] 2> 5226560 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 5226560 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 5226560 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 5226560 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226560 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226560 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226560 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226560 WARN (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226562 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 5226562 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 5226563 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 5226563 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 5226565 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226565 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226565 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 5226565 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226566 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=2
[junit4] 2> 5226571 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 5226572 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 5226572 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=15, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.35225842121746487]
[junit4] 2> 5226575 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(HdfsDirectory@hdfs://localhost:38955/solr_hdfs_home/control_collection/core_node1/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5ef182b3; maxCacheMB=192.0 maxMergeSizeMB=16.0),segFN=segments_1,generation=1}
[junit4] 2> 5226575 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 5226575 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5209ee84[collection1] main]
[junit4] 2> 5226575 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226575 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226575 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226576 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 5226576 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {}
[junit4] 2> 5226576 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226576 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226576 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226576 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 5226576 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 5226577 INFO (searcherExecutor-13025-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5209ee84[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 5226577 WARN (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.h.HdfsLocalityReporter Could not retrieve locality information for hdfs://localhost:59745/solr3 due to exception: java.net.ConnectException: Call From lucene1-us-west/10.41.0.5 to localhost:59745 failed on connection exception: java.net.ConnectException: Connection refused; For more details see: http://wiki.apache.org/hadoop/ConnectionRefused
[junit4] 2> 5226577 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226577 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226577 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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> 5226577 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ 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 1535461754673299456
[junit4] 2> 5226579 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 1.0ms to seed version buckets with highest version 1535461754673299456
[junit4] 2> 5226579 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1
[junit4] 2> 5226580 INFO (coreLoadExecutor-13024-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: collection1
[junit4] 2> 5226580 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ 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:38303 collection:control_collection shard:shard1
[junit4] 2> 5226580 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ 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> 5226582 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ 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/95966359574478852-core_node1-n_0000000000
[junit4] 2> 5226582 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ 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> 5226583 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 5226583 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ 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> 5226583 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] 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> 5226583 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:38303/collection1/
[junit4] 2> 5226584 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 5226584 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:38303/collection1/ has no replicas
[junit4] 2> 5226584 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 5226585 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ 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/95966359574478852-core_node1-n_0000000000
[junit4] 2> 5226586 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ 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:38303/collection1/ shard1
[junit4] 2> 5226587 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] 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:38303",
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"} current state version: 1
[junit4] 2> 5226688 INFO (zkCallback-5104-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ ] 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> 5226737 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController We are http://127.0.0.1:38303/collection1/ and leader is http://127.0.0.1:38303/collection1/
[junit4] 2> 5226737 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ 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:38303
[junit4] 2> 5226737 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 5226737 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController publishing state=active
[junit4] 2> 5226737 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ 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> 5226738 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] 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:38303",
[junit4] 2> "node_name":"127.0.0.1:38303_",
[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> 5226739 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] 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:38303",
[junit4] 2> "node_name":"127.0.0.1:38303_",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 5226739 INFO (coreZkRegister-13018-thread-1-processing-n:127.0.0.1:38303_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38303_ 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> 5226840 INFO (zkCallback-5104-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ ] 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> 5226897 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 5226897 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 5226898 INFO (zkCallback-5106-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3db1e460 name:ZooKeeperConnection Watcher:127.0.0.1:51333/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5226898 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 5226898 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 5226898 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 5226899 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 5226899 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 5226899 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Creating collection1 with stateFormat=2
[junit4] 2> 5226899 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 5226900 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 5226900 INFO (zkCallback-5107-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3e5c774d name:ZooKeeperConnection Watcher:127.0.0.1:51333/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5226900 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 5226901 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 5226902 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"create",
[junit4] 2> "name":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "stateFormat":"2"} current state version: 3
[junit4] 2> 5226902 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1
[junit4] 2> 5226968 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/shard-1-001/cores/collection1
[junit4] 2> 5226968 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/shard-1-001
[junit4] 2> 5226969 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 5226970 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6ea27c65{/,null,AVAILABLE}
[junit4] 2> 5226970 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.e.j.s.ServerConnector Started ServerConnector@77aad4de{HTTP/1.1,[http/1.1]}{127.0.0.1:38744}
[junit4] 2> 5226971 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.e.j.s.Server Started @5229973ms
[junit4] 2> 5226971 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=hdfs://localhost:38955/hdfs__localhost_38955__x1_jenkins_jenkins-slave_workspace_Lucene-Solr-NightlyTests-6.0_solr_build_solr-core_test_J1_temp_solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001_tempDir-002_jetty1, solrconfig=solrconfig.xml, hostContext=/, hostPort=38744, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/shard-1-001/cores}
[junit4] 2> 5226972 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@73d16e93
[junit4] 2> 5226972 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/shard-1-001'
[junit4] 2> 5226972 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 5226972 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 5226972 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 5226972 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 5226973 INFO (zkCallback-5108-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@7d83d9f8 name:ZooKeeperConnection Watcher:127.0.0.1:51333/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5226973 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 5226973 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 5226974 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 5226974 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/shard-1-001/solr.xml
[junit4] 2> 5226977 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/shard-1-001/cores
[junit4] 2> 5226977 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.CoreContainer New CoreContainer 221405923
[junit4] 2> 5226977 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/shard-1-001]
[junit4] 2> 5226977 WARN (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/shard-1-001/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/shard-1-001/lib
[junit4] 2> 5226978 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] 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> 5226978 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 5226979 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 5226979 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 5226979 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:51333/solr
[junit4] 2> 5226979 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 5226979 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 5226979 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 5226980 INFO (zkCallback-5111-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@469cfc20 name:ZooKeeperConnection Watcher:127.0.0.1:51333 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5226980 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 5226980 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 5226981 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$29/699737714@662b0f2c
[junit4] 2> 5226981 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 5226981 INFO (zkCallback-5112-thread-1-processing-n:127.0.0.1:38744_) [n:127.0.0.1:38744_ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@5b85a981 name:ZooKeeperConnection Watcher:127.0.0.1:51333/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5226981 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 5226984 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 5226985 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 5226986 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 5226986 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/95966359574478857-127.0.0.1:38744_-n_0000000001
[junit4] 2> 5226987 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/95966359574478852-127.0.0.1:38303_-n_0000000000 to know if I could be the leader
[junit4] 2> 5226987 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.ZkController Publish node=127.0.0.1:38744_ as DOWN
[junit4] 2> 5226988 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:38744_"} current state version: 3
[junit4] 2> 5226988 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:38744_
[junit4] 2> 5226988 INFO (OverseerStateUpdate-95966359574478852-127.0.0.1:38303_-n_0000000000) [n:127.0.0.1:38303_ ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/collection1/state.json
[junit4] 2> 5227090 INFO (zkCallback-5106-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> 5227091 INFO (zkCallback-5104-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ ] 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> 5227091 INFO (zkCallback-5112-thread-1-processing-n:127.0.0.1:38744_) [n:127.0.0.1:38744_ ] 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> 5227988 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38744_
[junit4] 2> 5227988 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:38744_
[junit4] 2> 5227989 INFO (zkCallback-5106-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> 5227989 INFO (zkCallback-5104-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ ] 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> 5227989 INFO (zkCallback-5106-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 5227992 INFO (zkCallback-5112-thread-1-processing-n:127.0.0.1:38744_) [n:127.0.0.1:38744_ ] 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> 5227994 INFO (zkCallback-5104-thread-1-processing-n:127.0.0.1:38303_) [n:127.0.0.1:38303_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 5227995 INFO (zkCallback-5112-thread-1-processing-n:127.0.0.1:38744_) [n:127.0.0.1:38744_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 5227996 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 5227996 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 5227997 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/shard-1-001/cores
[junit4] 2> 5227997 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] 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> 5227997 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.CorePropertiesLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_25DEEA7E1DC473DD-001/shard-1-001/cores/collection1
[junit4] 2> 5227997 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions
[junit4] 2> 5227998 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/J1
[junit4] 2> 5227998 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[25DEEA7E1DC473DD]) [n:127.0.0.1:38744_ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 5227998 INFO (coreLoadExecutor-13035-thread-1-processing-n:127.0.0.1:38744_) [n:127.0.0.1:38744_ c:collection1 x:collection1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 5227998 INFO (coreLoadExecutor-13035-thread-1-processing-n:127.0.0.1:38744_) [n:127.0.0.1:38744_ c:collection1 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 5227999 INFO (coreLoadExecutor-13035-thread-1-processing-n:127.0.0.1:38744_) [n:127.0.0.1:38744_ c:collection1 x:collection1] o.a.s.c.ZkController Registering watch for collection collection1
[junit4] 2> 5227999 INFO (coreLoadExecutor-13035-thread-1-processing-n:127.0.0.1:38744_) [n:127.0.0.1:38744_ c:collection1 x:collection1] o.a.s.c.c.ZkStateReader addZkWatch [collection1]
[junit4] 2> 5227999 INFO (coreLoadExecutor-13035-thread-1-processing-n:127.0.0.1:38744_) [n:127.0.0.1:38744_ c:collection1 x:c
[...truncated too long message...]
ction1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57695_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [http://127.0.0.1:44096/collection1/] and I am [http://127.0.0.1:57695/collection1/]
[junit4] 2> 8792852 INFO (recoveryExecutor-1328-thread-13-processing-n:127.0.0.1:57695_ x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57695_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.ZkController publishing state=recovering
[junit4] 2> 8792853 INFO (recoveryExecutor-1328-thread-13-processing-n:127.0.0.1:57695_ x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57695_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 8792853 WARN (recoveryExecutor-1328-thread-13-processing-n:127.0.0.1:57695_ x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57695_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.ZkController Unable to read /collections/collection1/leader_initiated_recovery/shard1/core_node4 due to: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_initiated_recovery/shard1/core_node4
[junit4] 2> 8792853 ERROR (recoveryExecutor-1328-thread-13-processing-n:127.0.0.1:57695_ x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57695_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy Error while trying to recover. core=collection1:org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue/qn-
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:383)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:380)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:380)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.offer(DistributedQueue.java:248)
[junit4] 2> at org.apache.solr.cloud.ZkController.publish(ZkController.java:1185)
[junit4] 2> at org.apache.solr.cloud.ZkController.publish(ZkController.java:1097)
[junit4] 2> at org.apache.solr.cloud.ZkController.publish(ZkController.java:1093)
[junit4] 2> at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:336)
[junit4] 2> at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:224)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 8792853 INFO (recoveryExecutor-1328-thread-13-processing-n:127.0.0.1:57695_ x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57695_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy Replay not started, or was not successful... still buffering updates.
[junit4] 2> 8792853 ERROR (recoveryExecutor-1328-thread-13-processing-n:127.0.0.1:57695_ x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57695_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy Recovery failed - trying again... (104)
[junit4] 2> 8792854 INFO (recoveryExecutor-1328-thread-13-processing-n:127.0.0.1:57695_ x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57695_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy Wait [12.0] seconds before trying to recover again (attempt=105)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene60): {other_tl1=Lucene50(blocksize=128), range_facet_l_dv=PostingsFormat(name=LuceneFixedGap), _version_=Lucene50(blocksize=128), multiDefault=PostingsFormat(name=Asserting), a_t=Lucene50(blocksize=128), intDefault=Lucene50(blocksize=128), a_i1=Lucene50(blocksize=128), id=PostingsFormat(name=LuceneFixedGap), range_facet_i_dv=Lucene50(blocksize=128), text=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), range_facet_l=Lucene50(blocksize=128), timestamp=Lucene50(blocksize=128)}, docValues:{range_facet_l_dv=DocValuesFormat(name=Direct), range_facet_i_dv=DocValuesFormat(name=Lucene54), timestamp=DocValuesFormat(name=Lucene54)}, maxPointsInLeafNode=1629, maxMBSortInHeap=5.761549454592406, sim=RandomSimilarity(queryNorm=false,coord=yes): {}, locale=el-CY, timezone=Asia/Pyongyang
[junit4] 2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8.0_74 (64-bit)/cpus=4,threads=227,free=15299080,total=516423680
[junit4] 2> NOTE: All tests run in this JVM: [DistributedFacetPivotLongTailTest, DeleteShardTest, FieldAnalysisRequestHandlerTest, TestWriterPerf, SolrTestCaseJ4Test, BaseCdcrDistributedZkTest, TestSearcherReuse, HdfsThreadLeakTest, TestSolrJ, OverseerStatusTest, TestBlendedInfixSuggestions, BlockJoinFacetSimpleTest, TestManagedSchema, TestTestInjection, CurrencyFieldXmlFileTest, TestIndexSearcher, DirectSolrConnectionTest, TestSuggestSpellingConverter, TestManagedSynonymFilterFactory, TriLevelCompositeIdRoutingTest, TestReload, TestElisionMultitermQuery, SuggestComponentContextFilterQueryTest, DirectUpdateHandlerTest, CollectionStateFormat2Test, CollectionsAPISolrJTest, TestIndexingPerformance, StatelessScriptUpdateProcessorFactoryTest, CircularListTest, TestReplicaProperties, AnalyticsQueryTest, RuleEngineTest, TestHighFrequencyDictionaryFactory, UpdateParamsTest, TestSort, TestCharFilters, ShowFileRequestHandlerTest, TestReRankQParserPlugin, TestDistribDocBasedVersion, FullSolrCloudDistribCmdsTest, PluginInfoTest, HLLSerializationTest, HighlighterConfigTest, TestSearchPerf, TestZkChroot, TermVectorComponentDistributedTest, TestMinMaxOnMultiValuedField, SolrCoreCheckLockOnStartupTest, TestExactSharedStatsCache, QueryResultKeyTest, TestJmxIntegration, TestCSVResponseWriter, TestCustomSort, TestUseDocValuesAsStored, TestSSLRandomization, ScriptEngineTest, JavabinLoaderTest, DeleteInactiveReplicaTest, HdfsWriteToMultipleCollectionsTest, SimpleFacetsTest, DistribDocExpirationUpdateProcessorTest, RequestHandlersTest, InfoHandlerTest, TestSolrQueryParserResource, SuggesterTSTTest, RegexBoostProcessorTest, TestRecovery, SampleTest, TestReversedWildcardFilterFactory, DistributedVersionInfoTest, TestExtendedDismaxParser, TestExpandComponent, TestCoreDiscovery, TestSolrQueryResponse, TestMissingGroups, TestReplicationHandlerBackup, TestSchemaVersionResource, TestCustomDocTransformer, SliceStateTest, TestSolrDeletionPolicy1, TestNonDefinedSimilarityFactory, ConnectionManagerTest, AssignTest, SimpleMLTQParserTest, TestPHPSerializedResponseWriter, TestDynamicFieldCollectionResource, CoreAdminCreateDiscoverTest, SuggesterTest, QueryParsingTest, BadIndexSchemaTest, HdfsBasicDistributedZkTest, TestSQLHandler, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest]
[junit4] ERROR 0.00s J2 | CollectionsAPIDistributedZkTest (suite) <<<
[junit4] > Throwable #1: java.lang.OutOfMemoryError: Java heap space
[junit4] Completed [584/584 (2!)] on J2 in 7204.26s, 1 test, 1 error <<< FAILURES!
[...truncated 2 lines...]
[junit4] JVM J2: stdout was not empty, see: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build/solr-core/test/temp/junit4-J2-20160527_050009_639.sysout
[junit4] >>> JVM J2 emitted unexpected output (verbatim) ----
[junit4] java.lang.OutOfMemoryError: GC overhead limit exceeded
[junit4] Dumping heap to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/heapdumps/java_pid28980.hprof ...
[junit4] Heap dump file created [725323722 bytes in 16.623 secs]
[junit4] <<< JVM J2: EOF ----
[...truncated 11 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/build.xml:747: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/build.xml:684: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/build.xml:233: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/solr/common-build.xml:527: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/lucene/common-build.xml:1457: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.0/lucene/common-build.xml:1014: There were test failures: 584 suites (10 ignored), 2340 tests, 1 suite-level error, 1 error, 31 ignored (16 assumptions) [seed: 25DEEA7E1DC473DD]
Total time: 275 minutes 31 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