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 2015/06/20 03:05:27 UTC
[JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 716 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/716/
2 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test
Error Message:
Captured an uncaught exception in thread: Thread[id=16497, name=collection4, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=16497, name=collection4, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:53032/uxupv, http://127.0.0.1:59222/uxupv, http://127.0.0.1:38217/uxupv, http://127.0.0.1:55026/uxupv, http://127.0.0.1:57926/uxupv]
at __randomizedtesting.SeedInfo.seed([E7088F6DFBD3183F]:0)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:896)
Caused by: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:53032/uxupv, http://127.0.0.1:59222/uxupv, http://127.0.0.1:38217/uxupv, http://127.0.0.1:55026/uxupv, http://127.0.0.1:57926/uxupv]
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:355)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799)
at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1572)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1593)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:886)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:38217/uxupv: KeeperErrorCode = Session expired for /overseer/collection-queue-work/qn-
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328)
... 7 more
FAILED: org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.test
Error Message:
Captured an uncaught exception in thread: Thread[id=8693, name=collection4, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=8693, name=collection4, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest]
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:60005: Could not find collection : awholynewstresscollection_collection4_0
at __randomizedtesting.SeedInfo.seed([E7088F6DFBD3183F]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799)
at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:893)
Build Log:
[...truncated 10806 lines...]
[junit4] Suite: org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/init-core-data-001
[junit4] 2> 933962 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false)
[junit4] 2> 933962 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
[junit4] 1> Formatting using clusterid: testClusterID
[junit4] 2> 934004 WARN (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
[junit4] 2> 934026 WARN (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 934031 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 934043 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-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_35902_hdfs____gyekub/webapp
[junit4] 2> 934149 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
[junit4] 2> 934508 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:35902
[junit4] 2> 934622 WARN (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 934624 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 934640 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-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_47695_datanode____449m8m/webapp
[junit4] 2> 934740 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
[junit4] 2> 935107 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:47695
[junit4] 2> 935186 WARN (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 935188 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 935226 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-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_53978_datanode____.4ts9st/webapp
[junit4] 2> 935315 INFO (IPC Server handler 3 on 39691) [ ] BlockStateChange BLOCK* processReport: from storage DS-b0b9e55f-383d-46e5-8b5c-03f2431dafb6 node DatanodeRegistration(127.0.0.1, datanodeUuid=42f45d32-9bfd-4dc7-972e-7eb1e18ec80c, infoPort=47695, ipcPort=38522, storageInfo=lv=-56;cid=testClusterID;nsid=708323866;c=0), blocks: 0, hasStaleStorages: true, processing time: 1 msecs
[junit4] 2> 935315 INFO (IPC Server handler 3 on 39691) [ ] BlockStateChange BLOCK* processReport: from storage DS-e7de499e-f237-4c46-8a46-2d987e5f524e node DatanodeRegistration(127.0.0.1, datanodeUuid=42f45d32-9bfd-4dc7-972e-7eb1e18ec80c, infoPort=47695, ipcPort=38522, storageInfo=lv=-56;cid=testClusterID;nsid=708323866;c=0), blocks: 0, hasStaleStorages: false, processing time: 0 msecs
[junit4] 2> 935366 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
[junit4] 2> 935770 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:53978
[junit4] 2> 935897 INFO (IPC Server handler 4 on 39691) [ ] BlockStateChange BLOCK* processReport: from storage DS-edfe2ceb-132c-47af-bc8a-bf72808443c9 node DatanodeRegistration(127.0.0.1, datanodeUuid=181437a4-8240-4b47-9a6d-cba07753b1f9, infoPort=53978, ipcPort=38807, storageInfo=lv=-56;cid=testClusterID;nsid=708323866;c=0), blocks: 0, hasStaleStorages: true, processing time: 1 msecs
[junit4] 2> 935898 INFO (IPC Server handler 4 on 39691) [ ] BlockStateChange BLOCK* processReport: from storage DS-e993263d-e9c8-4617-affd-8042c1d7aa84 node DatanodeRegistration(127.0.0.1, datanodeUuid=181437a4-8240-4b47-9a6d-cba07753b1f9, infoPort=53978, ipcPort=38807, storageInfo=lv=-56;cid=testClusterID;nsid=708323866;c=0), blocks: 0, hasStaleStorages: false, processing time: 0 msecs
[junit4] 2> 935953 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 935953 INFO (Thread-3270) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 935953 INFO (Thread-3270) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 936053 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.ZkTestServer start zk server on port:42582
[junit4] 2> 936054 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 936054 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 936057 INFO (zkCallback-766-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@638a3ab6 name:ZooKeeperConnection Watcher:127.0.0.1:42582 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 936057 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 936057 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 936057 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 936060 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 936062 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 936062 INFO (zkCallback-767-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@5d96fc65 name:ZooKeeperConnection Watcher:127.0.0.1:42582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 936063 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 936063 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 936063 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1
[junit4] 2> 936065 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards
[junit4] 2> 936067 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection
[junit4] 2> 936068 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards
[junit4] 2> 936070 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 936070 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 936072 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 936073 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml
[junit4] 2> 936074 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 936075 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 936076 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 936076 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt
[junit4] 2> 936078 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 936078 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt
[junit4] 2> 936079 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 936080 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml
[junit4] 2> 936081 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 936082 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 936083 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 936083 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 936085 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 936085 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 936086 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 936087 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 936088 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 936088 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt
[junit4] 2> 936090 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 936091 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 936092 INFO (zkCallback-768-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6ad08d52 name:ZooKeeperConnection Watcher:127.0.0.1:42582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 936092 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 936092 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 936094 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 936094 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 936103 INFO (zkCallback-769-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4047aa63 name:ZooKeeperConnection Watcher:127.0.0.1:42582 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 936103 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 936103 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 936103 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 936106 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 936107 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 936118 INFO (zkCallback-770-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@7bb041c9 name:ZooKeeperConnection Watcher:127.0.0.1:42582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 936118 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 936119 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 936119 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf2/solrconfig.xml
[junit4] 2> 936119 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/solrconfig.xml
[junit4] 2> 936125 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
[junit4] 2> 936125 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/schema.xml
[junit4] 2> 936133 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf2/enumsConfig.xml
[junit4] 2> 936133 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/enumsConfig.xml
[junit4] 2> 936135 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 936135 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 936136 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
[junit4] 2> 936136 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/stopwords.txt
[junit4] 2> 936137 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
[junit4] 2> 936137 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/protwords.txt
[junit4] 2> 936138 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
[junit4] 2> 936139 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/currency.xml
[junit4] 2> 936140 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
[junit4] 2> 936140 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/open-exchange-rates.json
[junit4] 2> 936141 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
[junit4] 2> 936141 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
[junit4] 2> 936142 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
[junit4] 2> 936142 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/old_synonyms.txt
[junit4] 2> 936144 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
[junit4] 2> 936144 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/synonyms.txt
[junit4] 2> 936145 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
[junit4] 2> 936145 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/elevate.xml
[junit4] 2> 936436 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/control-001/cores/collection1
[junit4] 2> 936438 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.e.j.s.Server jetty-9.2.11.v20150529
[junit4] 2> 936440 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6085d6d{/,null,AVAILABLE}
[junit4] 2> 936444 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.e.j.s.ServerConnector Started ServerConnector@154da174{SSL-http/1.1}{127.0.0.1:50440}
[junit4] 2> 936444 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.e.j.s.Server Started @939601ms
[junit4] 2> 936444 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=hdfs://localhost:39691/hdfs__localhost_39691__x1_jenkins_jenkins-slave_workspace_Lucene-Solr-NightlyTests-trunk_solr_build_solr-core_test_J2_temp_solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001_tempDir-002_control_data, hostContext=/, hostPort=50440, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/control-001/cores}
[junit4] 2> 936446 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@c387f44
[junit4] 2> 936446 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/control-001/'
[junit4] HEARTBEAT J0 PID(26478@lucene1-us-west): 2015-06-19T20:23:26, stalled for 300s at: TestDistributedSearch.test
[junit4] 2> 936460 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/control-001/solr.xml
[junit4] 2> 936465 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.CoresLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/control-001/cores
[junit4] 2> 936465 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.CoreContainer New CoreContainer 979576554
[junit4] 2> 936466 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/control-001/]
[junit4] 2> 936466 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.CoreContainer loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/control-001/lib
[junit4] 2> 936466 WARN (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.SolrResourceLoader Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/control-001/lib).
[junit4] 2> 936473 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] 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> 936475 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 936476 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 936476 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 936476 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42582/solr
[junit4] 2> 936477 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 936477 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 936482 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 936484 INFO (zkCallback-772-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@768ee744 name:ZooKeeperConnection Watcher:127.0.0.1:42582 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 936485 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 936485 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 936488 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 936489 INFO (zkCallback-773-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1debbac0 name:ZooKeeperConnection Watcher:127.0.0.1:42582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 936489 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 936490 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
[junit4] 2> 936491 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
[junit4] 2> 936492 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
[junit4] 2> 936494 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
[junit4] 2> 936495 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
[junit4] 2> 936498 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 936499 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 936500 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 936501 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50440_
[junit4] 2> 936501 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:50440_
[junit4] 2> 936502 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
[junit4] 2> 936503 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
[junit4] 2> 936505 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 936509 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94028379560280070-127.0.0.1:50440_-n_0000000000
[junit4] 2> 936510 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:50440_
[junit4] 2> 936510 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
[junit4] 2> 936511 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.Overseer Overseer (id=94028379560280070-127.0.0.1:50440_-n_0000000000) starting
[junit4] 2> 936514 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
[junit4] 2> 936518 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=10000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 936518 INFO (OverseerCollectionProcessor-94028379560280070-127.0.0.1:50440_-n_0000000000) [n:127.0.0.1:50440_ ] o.a.s.c.OverseerCollectionProcessor Process current queue of collection creations
[junit4] 2> 936519 INFO (OverseerStateUpdate-94028379560280070-127.0.0.1:50440_-n_0000000000) [n:127.0.0.1:50440_ ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 936519 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 936522 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 936522 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 936523 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.CoresLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/control-001/cores
[junit4] 2> 936524 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.SolrCore Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/control-001/cores/collection1, collection=control_collection, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/control-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
[junit4] 2> 936524 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.CoresLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/control-001/cores/collection1/
[junit4] 2> 936524 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.c.CoresLocator Found 1 core definitions
[junit4] 2> 936526 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2
[junit4] 2> 936526 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [n:127.0.0.1:50440_ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 936526 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 936526 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 936527 INFO (zkCallback-773-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 936527 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.c.ZkController look for our core node name
[junit4] 2> 936527 INFO (OverseerStateUpdate-94028379560280070-127.0.0.1:50440_-n_0000000000) [n:127.0.0.1:50440_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:50440",
[junit4] 2> "node_name":"127.0.0.1:50440_",
[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> 936528 INFO (OverseerStateUpdate-94028379560280070-127.0.0.1:50440_-n_0000000000) [n:127.0.0.1:50440_ ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:50440",
[junit4] 2> "node_name":"127.0.0.1:50440_",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 936528 INFO (OverseerStateUpdate-94028379560280070-127.0.0.1:50440_-n_0000000000) [n:127.0.0.1:50440_ ] o.a.s.c.o.ClusterStateMutator building a new cName: control_collection
[junit4] 2> 936528 INFO (OverseerStateUpdate-94028379560280070-127.0.0.1:50440_-n_0000000000) [n:127.0.0.1:50440_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 936531 INFO (zkCallback-773-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ ] 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> 936532 INFO (zkCallback-773-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 1
[junit4] 2> 937527 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
[junit4] 2> 937527 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.c.ZkController Check for collection zkNode:control_collection
[junit4] 2> 937528 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.c.ZkController Collection zkNode exists
[junit4] 2> 937528 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
[junit4] 2> 937529 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 937529 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/control-001/cores/collection1/'
[junit4] 2> 937542 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0
[junit4] 2> 937546 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 937549 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0
[junit4] 2> 937557 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.c.Config Loaded SolrConfig: solrconfig.xml
[junit4] 2> 937558 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.s.IndexSchema Reading Solr Schema from /configs/conf1/schema.xml
[junit4] 2> 937562 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 937653 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 937658 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.s.IndexSchema default search field in schema is text
[junit4] 2> 937659 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 937667 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 937669 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 937671 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 937671 WARN (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 937671 WARN (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 937672 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 937672 WARN (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 937672 WARN (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 937672 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 937673 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.HdfsDirectoryFactory
[junit4] 2> 937673 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:39691/solr_hdfs_home
[junit4] 2> 937673 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 937673 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/control-001/cores/collection1/], dataDir=[null]
[junit4] 2> 937673 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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@37e17ab
[junit4] 2> 937674 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:39691/solr_hdfs_home/control_collection/core_node1/data
[junit4] 2> 937719 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.h.HdfsLocalityReporter Registering direcotry hdfs://localhost:39691/solr_hdfs_home/control_collection/core_node1/data for locality metrics.
[junit4] 2> 937719 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for hdfs://localhost:39691/solr_hdfs_home/control_collection/core_node1/data
[junit4] 2> 937721 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=hdfs://localhost:39691/solr_hdfs_home/control_collection/core_node1/data/index/
[junit4] 2> 937732 WARN (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory 'hdfs:/localhost:39691/solr_hdfs_home/control_collection/core_node1/data/index' doesn't exist. Creating new index...
[junit4] 2> 937732 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:39691/solr_hdfs_home/control_collection/core_node1/data/index
[junit4] 2> 937748 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.h.HdfsLocalityReporter Registering direcotry hdfs://localhost:39691/solr_hdfs_home/control_collection/core_node1/data/index for locality metrics.
[junit4] 2> 937748 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for hdfs://localhost:39691/solr_hdfs_home/control_collection/core_node1/data/index
[junit4] 2> 937749 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=166353292, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 937785 INFO (IPC Server handler 3 on 39691) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42076 is added to blk_1073741825_1001{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-b0b9e55f-383d-46e5-8b5c-03f2431dafb6:NORMAL:127.0.0.1:33526|RBW], ReplicaUnderConstruction[[DISK]DS-edfe2ceb-132c-47af-bc8a-bf72808443c9:NORMAL:127.0.0.1:42076|RBW]]} size 0
[junit4] 2> 937790 INFO (IPC Server handler 5 on 39691) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:33526 is added to blk_1073741825_1001 size 71
[junit4] 2> 937793 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(HdfsDirectory@b6c5b335 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5873e64; maxCacheMB=192.0 maxMergeSizeMB=16.0),segFN=segments_1,generation=1}
[junit4] 2> 937793 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
[junit4] 2> 937811 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 937811 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
[junit4] 2> 937811 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 937812 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 937812 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 937812 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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> 937812 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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> 937812 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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> 937812 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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> 937813 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:50440_ 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:39691/solr_hdfs_home/control_collection/core_node1/data/
[junit4] 2> 937814 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 937815 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 937816 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 937817 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 937820 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,/update/csv,/update/json/docs,/admin/luke,/admin/segments,/get,/admin/system,/replication,/admin/properties,/config,/schema,/admin/plugins,/admin/logging,/update/json,/admin/threads,/admin/ping,/update,/admin/file
[junit4] 2> 937820 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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> 937821 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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> 937821 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Initializing HdfsUpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 tlogDfsReplication=2
[junit4] 2> 937833 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Hard AutoCommit: disabled
[junit4] 2> 937833 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Soft AutoCommit: disabled
[junit4] 2> 937835 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=33, maxMergedSegmentMB=76.5771484375, floorSegmentMB=1.470703125, forceMergeDeletesPctAllowed=24.302973055038148, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 937864 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(HdfsDirectory@b6c5b335 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5873e64; maxCacheMB=192.0 maxMergeSizeMB=16.0),segFN=segments_1,generation=1}
[junit4] 2> 937864 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
[junit4] 2> 937864 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@7e33941c[collection1] main
[junit4] 2> 937864 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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> 937865 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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> 937865 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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> 937865 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 937866 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {}
[junit4] 2> 937866 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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> 937866 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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> 937867 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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> 937867 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 937867 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 937868 INFO (searcherExecutor-2296-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7e33941c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 937870 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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> 937870 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 256 version buckets from index
[junit4] 2> 937871 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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> 937871 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ 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 1504454074973552640
[junit4] 2> 937871 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 1 ms to seed version buckets with highest version 1504454074973552640
[junit4] 2> 937871 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1
[junit4] 2> 937873 INFO (coreLoadExecutor-2295-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: collection1
[junit4] 2> 937874 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController Register replica - core:collection1 address:https://127.0.0.1:50440 collection:control_collection shard:shard1
[junit4] 2> 937875 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ 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> 937878 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ 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/94028379560280070-core_node1-n_0000000000
[junit4] 2> 937879 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard shard1
[junit4] 2> 937880 INFO (zkCallback-773-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 937880 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 937880 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ 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> 937880 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:50440/collection1/
[junit4] 2> 937880 INFO (OverseerStateUpdate-94028379560280070-127.0.0.1:50440_-n_0000000000) [n:127.0.0.1:50440_ ] 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> 937881 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 937881 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy https://127.0.0.1:50440/collection1/ has no replicas
[junit4] 2> 937881 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:50440/collection1/ shard1
[junit4] 2> 937881 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 937884 INFO (zkCallback-773-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 937884 INFO (OverseerStateUpdate-94028379560280070-127.0.0.1:50440_-n_0000000000) [n:127.0.0.1:50440_ ] 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":"https://127.0.0.1:50440",
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"} current state version: 1
[junit4] 2> 937988 INFO (zkCallback-773-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ ] 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> 937990 INFO (zkCallback-773-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 2
[junit4] 2> 938030 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 938031 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 938032 INFO (zkCallback-775-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@610a971a name:ZooKeeperConnection Watcher:127.0.0.1:42582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 938032 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 938032 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 938032 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 938035 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 938035 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController We are https://127.0.0.1:50440/collection1/ and leader is https://127.0.0.1:50440/collection1/
[junit4] 2> 938035 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:50440
[junit4] 2> 938035 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 938035 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController publishing state=active
[junit4] 2> 938035 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Creating collection1 with stateFormat=2
[junit4] 2> 938035 INFO (coreZkRegister-2289-thread-1-processing-n:127.0.0.1:50440_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:50440_ 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> 938035 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 938037 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 938037 INFO (zkCallback-773-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 938038 INFO (OverseerStateUpdate-94028379560280070-127.0.0.1:50440_-n_0000000000) [n:127.0.0.1:50440_ ] 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":"https://127.0.0.1:50440",
[junit4] 2> "node_name":"127.0.0.1:50440_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"} current state version: 2
[junit4] 2> 938038 INFO (OverseerStateUpdate-94028379560280070-127.0.0.1:50440_-n_0000000000) [n:127.0.0.1:50440_ ] o.a.s.c.o.ReplicaMutator Update state numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:50440",
[junit4] 2> "node_name":"127.0.0.1:50440_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 938042 INFO (zkCallback-776-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@5c719a70 name:ZooKeeperConnection Watcher:127.0.0.1:42582/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 938042 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 938042 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 938049 INFO (zkCallback-773-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 938054 INFO (OverseerStateUpdate-94028379560280070-127.0.0.1:50440_-n_0000000000) [n:127.0.0.1:50440_ ] 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: 2
[junit4] 2> 938055 INFO (OverseerStateUpdate-94028379560280070-127.0.0.1:50440_-n_0000000000) [n:127.0.0.1:50440_ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1
[junit4] 2> 938055 INFO (zkCallback-773-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ ] 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> 938056 INFO (zkCallback-773-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 3
[junit4] 2> 938065 INFO (zkCallback-775-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> 938071 INFO (zkCallback-775-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 3
[junit4] 2> 938158 INFO (OverseerStateUpdate-94028379560280070-127.0.0.1:50440_-n_0000000000) [n:127.0.0.1:50440_ ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/collection1/state.json
[junit4] 2> 938159 INFO (zkCallback-775-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> 938159 INFO (zkCallback-773-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ ] 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> 938160 INFO (zkCallback-775-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 4
[junit4] 2> 938162 INFO (zkCallback-773-thread-1-processing-n:127.0.0.1:50440_) [n:127.0.0.1:50440_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 4
[junit4] 2> 938361 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/shard-1-001/cores/collection1
[junit4] 2> 938362 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/shard-1-001
[junit4] 2> 938363 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.e.j.s.Server jetty-9.2.11.v20150529
[junit4] 2> 938365 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1aca0984{/,null,AVAILABLE}
[junit4] 2> 938368 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.e.j.s.ServerConnector Started ServerConnector@5c065822{SSL-http/1.1}{127.0.0.1:52260}
[junit4] 2> 938369 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.e.j.s.Server Started @941525ms
[junit4] 2> 938369 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=hdfs://localhost:39691/hdfs__localhost_39691__x1_jenkins_jenkins-slave_workspace_Lucene-Solr-NightlyTests-trunk_solr_build_solr-core_test_J2_temp_solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001_tempDir-002_jetty1, solrconfig=solrconfig.xml, hostContext=/, hostPort=52260, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/shard-1-001/cores}
[junit4] 2> 938370 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@c387f44
[junit4] 2> 938370 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/shard-1-001/'
[junit4] 2> 938384 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/shard-1-001/solr.xml
[junit4] 2> 938389 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.CoresLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/shard-1-001/cores
[junit4] 2> 938389 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.CoreContainer New CoreContainer 1035470588
[junit4] 2> 938389 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/shard-1-001/]
[junit4] 2> 938389 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.CoreContainer loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/shard-1-001/lib
[junit4] 2> 938390 WARN (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.SolrResourceLoader Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_E7088F6DFBD3183F-001/shard-1-001/lib).
[junit4] 2> 938397 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] 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> 938399 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 938401 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 938401 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 938401 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42582/solr
[junit4] 2> 938401 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 938401 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 938402 INFO (TEST-HdfsCollectionsAPIDistributedZkTest.test-seed#[E7088F6DFBD3183F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 938403 INFO (zkCallback-778-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3eaf9e95 name:ZooKeeperConnection Watcher:127.0.0.1:42582 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 938404 I
[...truncated too long message...]
che.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328)
[junit4] > ... 7 moreThrowable #6: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=16493, name=collection0, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
[junit4] > Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:53032/uxupv, http://127.0.0.1:59222/uxupv, http://127.0.0.1:38217/uxupv, http://127.0.0.1:55026/uxupv, http://127.0.0.1:57926/uxupv]
[junit4] > at __randomizedtesting.SeedInfo.seed([E7088F6DFBD3183F]:0)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:896)
[junit4] > Caused by: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:53032/uxupv, http://127.0.0.1:59222/uxupv, http://127.0.0.1:38217/uxupv, http://127.0.0.1:55026/uxupv, http://127.0.0.1:57926/uxupv]
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:355)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799)
[junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:893)
[junit4] > Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:38217/uxupv
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:572)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328)
[junit4] > ... 5 more
[junit4] > Caused by: java.net.SocketTimeoutException: Read timed out
[junit4] > at java.net.SocketInputStream.socketRead0(Native Method)
[junit4] > at java.net.SocketInputStream.read(SocketInputStream.java:150)
[junit4] > at java.net.SocketInputStream.read(SocketInputStream.java:121)
[junit4] > at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160)
[junit4] > at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84)
[junit4] > at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273)
[junit4] > at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
[junit4] > at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
[junit4] > at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
[junit4] > at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
[junit4] > at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
[junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
[junit4] > at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
[junit4] > at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882)
[junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
[junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107)
[junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:466)
[junit4] > ... 9 more
[junit4] 2> 2110201 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[E7088F6DFBD3183F]-worker) [n:127.0.0.1:59222_uxupv c:awholynewstresscollection_collection4_0 s:shard2 r:core_node16 x:awholynewstresscollection_collection4_0_shard2_replica1] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene53): {other_tl1=PostingsFormat(name=Memory doPackFST= true), range_facet_l_dv=PostingsFormat(name=Asserting), _version_=PostingsFormat(name=Memory doPackFST= true), multiDefault=PostingsFormat(name=MockRandom), a_t=PostingsFormat(name=MockRandom), intDefault=PostingsFormat(name=Memory doPackFST= true), a_i1=PostingsFormat(name=MockRandom), id=PostingsFormat(name=Asserting), range_facet_i_dv=PostingsFormat(name=MockRandom), text=FSTOrd50, range_facet_l=PostingsFormat(name=MockRandom), timestamp=PostingsFormat(name=MockRandom)}, docValues:{range_facet_l_dv=DocValuesFormat(name=Memory), range_facet_i_dv=DocValuesFormat(name=Direct), timestamp=DocValuesFormat(name=Direct)}, sim=DefaultSimilarity, locale=ar_IQ, timezone=America/Porto_Acre
[junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.8.0_25 (64-bit)/cpus=4,threads=1,free=104141880,total=534249472
[junit4] 2> NOTE: All tests run in this JVM: [BasicFunctionalityTest, TestComplexPhraseQParserPlugin, HttpPartitionTest, CoreAdminHandlerTest, ClusterStateUpdateTest, ZkCLITest, TestNRTOpen, TestMacros, HighlighterMaxOffsetTest, BlockCacheTest, TestFieldTypeCollectionResource, TestLMDirichletSimilarityFactory, TestSolrCoreProperties, TestSortingResponseWriter, MigrateRouteKeyTest, TestOmitPositions, TestFieldSortValues, TestJsonRequest, TestConfigSets, TestCoreContainer, TestWriterPerf, IndexSchemaRuntimeFieldTest, NoCacheHeaderTest, TestLRUStatsCache, StatelessScriptUpdateProcessorFactoryTest, HdfsThreadLeakTest, ShowFileRequestHandlerTest, ParsingFieldUpdateProcessorsTest, SolrCmdDistributorTest, UUIDUpdateProcessorFallbackTest, BaseCdcrDistributedZkTest, TriLevelCompositeIdRoutingTest, TestOverriddenPrefixQueryForCustomFieldType, FieldMutatingUpdateProcessorTest, EchoParamsTest, ShardRoutingCustomTest, TestRTGBase, TestSearchPerf, SpellCheckComponentTest, HdfsRecoveryZkTest, TestFastLRUCache, IgnoreCommitOptimizeUpdateProcessorFactoryTest, TestAtomicUpdateErrorCases, TestCryptoKeys, TestSolrConfigHandlerConcurrent, RAMDirectoryFactoryTest, TestManagedSchema, TestRemoveLastDynamicCopyField, SolrPluginUtilsTest, DocumentAnalysisRequestHandlerTest, TestAnalyzedSuggestions, BufferStoreTest, TestDefaultStatsCache, TestManagedSchemaFieldTypeResource, TestReplicaProperties, TestFuzzyAnalyzedSuggestions, SystemInfoHandlerTest, HdfsWriteToMultipleCollectionsTest, ConvertedLegacyTest, TestCloudManagedSchema, TestDynamicLoading, SpatialFilterTest, AlternateDirectoryTest, HdfsChaosMonkeySafeLeaderTest, ScriptEngineTest, TestRandomMergePolicy, BadComponentTest, PreAnalyzedUpdateProcessorTest, TestManagedSchemaDynamicFieldResource, TestExpandComponent, CachingDirectoryFactoryTest, CopyFieldTest, TestCustomSort, TestLeaderElectionZkExpiry, TestTolerantSearch, TestRecoveryHdfs, TestCharFilters, CurrencyFieldOpenExchangeTest, RequestLoggingTest, TestEmbeddedSolrServerConstructors, ReturnFieldsTest, CacheHeaderTest, DistributedMLTComponentTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest]
[junit4] Completed [240/512] on J1 in 895.99s, 1 test, 1 error <<< FAILURES!
[...truncated 875 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:533: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:474: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:61: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/extra-targets.xml:39: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:230: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:513: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1426: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:981: There were test failures: 512 suites, 2015 tests, 2 errors, 20 ignored (10 assumptions)
Total time: 256 minutes 53 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
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 717 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/717/
3 tests failed.
REGRESSION: org.apache.solr.search.TestSearcherReuse.test
Error Message:
expected same:<Searcher@600ad70c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C3) Uninverting(_1(6.0.0):C2) Uninverting(_2(6.0.0):C1)))}> was not:<Searcher@5de2c8cf[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C3) Uninverting(_1(6.0.0):C2) Uninverting(_2(6.0.0):C1)))}>
Stack Trace:
java.lang.AssertionError: expected same:<Searcher@600ad70c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C3) Uninverting(_1(6.0.0):C2) Uninverting(_2(6.0.0):C1)))}> was not:<Searcher@5de2c8cf[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C3) Uninverting(_1(6.0.0):C2) Uninverting(_2(6.0.0):C1)))}>
at __randomizedtesting.SeedInfo.seed([A7CE6FE98D323E8F:2F9A503323CE5377]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotSame(Assert.java:641)
at org.junit.Assert.assertSame(Assert.java:580)
at org.junit.Assert.assertSame(Assert.java:593)
at org.apache.solr.search.TestSearcherReuse.assertSearcherHasNotChanged(TestSearcherReuse.java:247)
at org.apache.solr.search.TestSearcherReuse.test(TestSearcherReuse.java:117)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test
Error Message:
Captured an uncaught exception in thread: Thread[id=1910, name=collection2, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=1910, name=collection2, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:47592, http://127.0.0.1:48781, http://127.0.0.1:52380, http://127.0.0.1:53657, http://127.0.0.1:35017]
at __randomizedtesting.SeedInfo.seed([A7CE6FE98D323E8F]:0)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:896)
Caused by: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:47592, http://127.0.0.1:48781, http://127.0.0.1:52380, http://127.0.0.1:53657, http://127.0.0.1:35017]
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:355)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799)
at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:893)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:47592: KeeperErrorCode = Session expired for /overseer/collection-queue-work/qn-
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328)
... 5 more
FAILED: org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.test
Error Message:
Captured an uncaught exception in thread: Thread[id=8172, name=collection3, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=8172, name=collection3, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest]
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:42169/ntce/jk: Could not find collection : awholynewstresscollection_collection3_1
at __randomizedtesting.SeedInfo.seed([A7CE6FE98D323E8F]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799)
at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:893)
Build Log:
[...truncated 10018 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/init-core-data-001
[junit4] 2> 149200 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[A7CE6FE98D323E8F]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false)
[junit4] 2> 149200 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[A7CE6FE98D323E8F]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
[junit4] 2> 149207 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 149215 INFO (Thread-988) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 149215 INFO (Thread-988) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 149308 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.ZkTestServer start zk server on port:57511
[junit4] 2> 149308 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 149313 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 149326 INFO (zkCallback-113-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4c6697c8 name:ZooKeeperConnection Watcher:127.0.0.1:57511 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 149327 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 149327 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 149327 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 149330 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 149338 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 149339 INFO (zkCallback-114-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@45ed3aec name:ZooKeeperConnection Watcher:127.0.0.1:57511/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 149341 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 149341 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 149341 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1
[junit4] 2> 149344 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards
[junit4] 2> 149347 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection
[junit4] 2> 149349 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards
[junit4] 2> 149351 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 149351 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 149356 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 149356 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml
[junit4] 2> 149359 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 149359 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 149361 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 149362 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt
[junit4] 2> 149363 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 149364 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt
[junit4] 2> 149365 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 149366 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml
[junit4] 2> 149368 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 149368 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 149370 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 149370 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 149372 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 149372 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 149374 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 149374 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 149376 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 149376 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt
[junit4] 2> 149732 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores/collection1
[junit4] 2> 149740 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.e.j.s.Server jetty-9.2.11.v20150529
[junit4] 2> 149826 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@f4046fd{/,null,AVAILABLE}
[junit4] 2> 149833 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.e.j.s.ServerConnector Started ServerConnector@5778e4ae{HTTP/1.1}{127.0.0.1:48781}
[junit4] 2> 149834 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.e.j.s.Server Started @153315ms
[junit4] 2> 149835 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/tempDir-001/control/data, hostContext=/, hostPort=48781, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores}
[junit4] 2> 149835 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@c387f44
[junit4] 2> 149838 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/'
[junit4] 2> 149853 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/solr.xml
[junit4] 2> 149863 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.CoresLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores
[junit4] 2> 149863 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.CoreContainer New CoreContainer 1406093189
[junit4] 2> 149863 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/]
[junit4] 2> 149863 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.CoreContainer loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/lib
[junit4] 2> 149863 WARN (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.SolrResourceLoader Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/lib).
[junit4] 2> 149871 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] 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> 149874 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 149874 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 149875 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 149875 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57511/solr
[junit4] 2> 149875 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 149875 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 149883 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 149883 INFO (zkCallback-116-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@519d3021 name:ZooKeeperConnection Watcher:127.0.0.1:57511 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 149884 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 149884 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 149890 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 149893 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@100e4ab2 name:ZooKeeperConnection Watcher:127.0.0.1:57511/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 149893 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 149894 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
[junit4] 2> 149896 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
[junit4] 2> 149898 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
[junit4] 2> 149899 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
[junit4] 2> 149901 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
[junit4] 2> 149902 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 149903 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 149904 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 149905 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48781_
[junit4] 2> 149906 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:48781_
[junit4] 2> 149907 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
[junit4] 2> 149908 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
[junit4] 2> 149909 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 149909 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94030712546983939-127.0.0.1:48781_-n_0000000000
[junit4] 2> 149910 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:48781_
[junit4] 2> 149910 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
[junit4] 2> 149911 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.Overseer Overseer (id=94030712546983939-127.0.0.1:48781_-n_0000000000) starting
[junit4] 2> 149914 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
[junit4] 2> 149919 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=10000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 149920 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 149922 INFO (OverseerCollectionProcessor-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] o.a.s.c.OverseerCollectionProcessor Process current queue of collection creations
[junit4] 2> 149931 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 149933 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 149933 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 149934 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.CoresLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores
[junit4] 2> 149935 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.SolrCore Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores/collection1, collection=control_collection, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
[junit4] 2> 149935 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.CoresLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores/collection1/
[junit4] 2> 149935 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.c.CoresLocator Found 1 core definitions
[junit4] 2> 149936 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 149936 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 149938 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 149938 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
[junit4] 2> 149938 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:48781_ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 149939 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] 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:48781",
[junit4] 2> "node_name":"127.0.0.1:48781_",
[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> 149939 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] 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:48781",
[junit4] 2> "node_name":"127.0.0.1:48781_",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 149940 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] o.a.s.c.o.ClusterStateMutator building a new cName: control_collection
[junit4] 2> 149940 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 149942 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] 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> 149943 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 1
[junit4] 2> 149944 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.c.ZkController look for our core node name
[junit4] 2> 149944 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
[junit4] 2> 149944 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.c.ZkController Check for collection zkNode:control_collection
[junit4] 2> 149945 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.c.ZkController Collection zkNode exists
[junit4] 2> 149945 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
[junit4] 2> 149948 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 149949 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores/collection1/'
[junit4] 2> 149973 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0
[junit4] 2> 149979 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 149983 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0
[junit4] 2> 149992 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.c.Config Loaded SolrConfig: solrconfig.xml
[junit4] 2> 149993 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.s.IndexSchema Reading Solr Schema from /configs/conf1/schema.xml
[junit4] 2> 149999 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 150123 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 150132 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.s.IndexSchema default search field in schema is text
[junit4] 2> 150133 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 150151 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 150153 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 150155 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 150156 WARN (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 150156 WARN (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 150156 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 150157 WARN (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 150157 WARN (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 150157 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 150157 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 150158 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores/collection1/], dataDir=[null]
[junit4] 2> 150158 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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@5cb10baf
[junit4] 2> 150158 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores/collection1/data
[junit4] 2> 150159 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores/collection1/data/index/
[junit4] 2> 150159 WARN (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 150160 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores/collection1/data/index
[junit4] 2> 150161 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=966355182, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 150205 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(MMapDirectory@/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/index-MMapDirectory-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6f307b86),segFN=segments_1,generation=1}
[junit4] 2> 150205 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
[junit4] 2> 150218 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 150219 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
[junit4] 2> 150219 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 150219 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 150219 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 150219 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150220 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150220 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150220 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150222 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 150223 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 150224 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 150224 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores/collection1/data/
[junit4] 2> 150225 WARN (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.DirectoryFactory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/control-001/cores/collection1/data/ does not point to a valid data directory; skipping clean-up of old index directories.
[junit4] 2> 150236 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 150246 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,/update/csv,/update/json/docs,/admin/luke,/admin/segments,/get,/admin/system,/replication,/admin/properties,/config,/schema,/admin/plugins,/admin/logging,/update/json,/admin/threads,/admin/ping,/update,/admin/file
[junit4] 2> 150246 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150253 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 150253 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150254 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Hard AutoCommit: disabled
[junit4] 2> 150254 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Soft AutoCommit: disabled
[junit4] 2> 150254 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=28.591796875, floorSegmentMB=0.76953125, forceMergeDeletesPctAllowed=8.925424591396729, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5246243728212946
[junit4] 2> 150260 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(MMapDirectory@/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/index-MMapDirectory-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6f307b86),segFN=segments_1,generation=1}
[junit4] 2> 150260 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
[junit4] 2> 150260 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@12b5816f[collection1] main
[junit4] 2> 150260 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150262 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150262 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150262 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 150262 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {}
[junit4] 2> 150262 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150263 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150263 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150263 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 150263 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 150264 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150264 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150264 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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> 150264 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ 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 1504491401844359168
[junit4] 2> 150266 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 2 ms to seed version buckets with highest version 1504491401844359168
[junit4] 2> 150266 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1
[junit4] 2> 150267 INFO (searcherExecutor-319-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@12b5816f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 150268 INFO (coreLoadExecutor-318-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: collection1
[junit4] 2> 150284 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ 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:48781 collection:control_collection shard:shard1
[junit4] 2> 150289 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ 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> 150295 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ 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/94030712546983939-core_node1-n_0000000000
[junit4] 2> 150296 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard shard1
[junit4] 2> 150297 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 150297 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 150297 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ 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> 150298 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:48781/collection1/
[junit4] 2> 150298 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 150298 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:48781/collection1/ has no replicas
[junit4] 2> 150298 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ 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:48781/collection1/ shard1
[junit4] 2> 150298 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 150299 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] 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> 150302 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 150303 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] 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:48781",
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"} current state version: 1
[junit4] 2> 150405 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] 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> 150406 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 2
[junit4] 2> 150440 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 150453 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController We are http://127.0.0.1:48781/collection1/ and leader is http://127.0.0.1:48781/collection1/
[junit4] 2> 150453 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ 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:48781
[junit4] 2> 150453 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 150453 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController publishing state=active
[junit4] 2> 150453 INFO (coreZkRegister-312-thread-1-processing-n:127.0.0.1:48781_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:48781_ 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> 150455 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 150456 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] 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:48781",
[junit4] 2> "node_name":"127.0.0.1:48781_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"} current state version: 2
[junit4] 2> 150457 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] o.a.s.c.o.ReplicaMutator Update state numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:48781",
[junit4] 2> "node_name":"127.0.0.1:48781_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 150464 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 150473 INFO (zkCallback-119-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@631fb797 name:ZooKeeperConnection Watcher:127.0.0.1:57511/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 150473 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 150473 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 150473 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 150477 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 150478 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Creating collection1 with stateFormat=2
[junit4] 2> 150478 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 150489 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 150492 INFO (zkCallback-120-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@af2102d name:ZooKeeperConnection Watcher:127.0.0.1:57511/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 150493 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 150493 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 150495 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 150498 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] 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: 2
[junit4] 2> 150498 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1
[junit4] 2> 150501 INFO (zkCallback-119-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> 150509 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] 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> 150512 INFO (zkCallback-119-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 3
[junit4] 2> 150512 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 3
[junit4] 2> 150614 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/collection1/state.json
[junit4] 2> 150615 INFO (zkCallback-119-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> 150615 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] 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> 150617 INFO (zkCallback-119-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 4
[junit4] 2> 150620 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 4
[junit4] 2> 150895 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/shard-1-001/cores/collection1
[junit4] 2> 150896 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/shard-1-001
[junit4] 2> 150899 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.e.j.s.Server jetty-9.2.11.v20150529
[junit4] 2> 150904 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@423f58f5{/,null,AVAILABLE}
[junit4] 2> 150904 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.e.j.s.ServerConnector Started ServerConnector@7feafcfd{HTTP/1.1}{127.0.0.1:53657}
[junit4] 2> 150905 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.e.j.s.Server Started @154385ms
[junit4] 2> 150905 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/, hostPort=53657, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/shard-1-001/cores}
[junit4] 2> 150905 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@c387f44
[junit4] 2> 150905 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/shard-1-001/'
[junit4] 2> 150929 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/shard-1-001/solr.xml
[junit4] 2> 150935 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.CoresLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/shard-1-001/cores
[junit4] 2> 150936 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.CoreContainer New CoreContainer 930125312
[junit4] 2> 150936 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/shard-1-001/]
[junit4] 2> 150936 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.CoreContainer loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/shard-1-001/lib
[junit4] 2> 150936 WARN (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.SolrResourceLoader Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/shard-1-001/lib).
[junit4] 2> 150948 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] 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> 150950 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 150950 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 150950 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 150950 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57511/solr
[junit4] 2> 150951 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 150951 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 150952 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 150969 INFO (zkCallback-122-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6e477909 name:ZooKeeperConnection Watcher:127.0.0.1:57511 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 150972 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 150973 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 150982 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 150983 INFO (zkCallback-123-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@b316139 name:ZooKeeperConnection Watcher:127.0.0.1:57511/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 150983 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 150987 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 151996 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53657_
[junit4] 2> 151997 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:53657_
[junit4] 2> 152005 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 152005 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94030712546983943-127.0.0.1:53657_-n_0000000001
[junit4] 2> 152006 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/94030712546983939-127.0.0.1:48781_-n_0000000000 to know if I could be the leader
[junit4] 2> 152007 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 152007 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 152008 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.c.CoresLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/shard-1-001/cores
[junit4] 2> 152009 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.c.SolrCore Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/shard-1-001/cores/collection1, collection=collection1, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/shard-1-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
[junit4] 2> 152009 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.c.CoresLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_A7CE6FE98D323E8F-001/shard-1-001/cores/collection1/
[junit4] 2> 152009 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.c.CoresLocator Found 1 core definitions
[junit4] 2> 152016 INFO (coreLoadExecutor-329-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ c:collection1 x:collection1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 152016 INFO (coreLoadExecutor-329-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ c:collection1 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 152026 INFO (zkCallback-117-thread-1-processing-n:127.0.0.1:48781_) [n:127.0.0.1:48781_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 152026 INFO (coreLoadExecutor-329-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ c:collection1 x:collection1] o.a.s.c.ZkController Registering watch for external collection collection1
[junit4] 2> 152026 INFO (coreLoadExecutor-329-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ c:collection1 x:collection1] o.a.s.c.c.ZkStateReader addZkWatch collection1
[junit4] 2> 152026 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] 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:53657",
[junit4] 2> "node_name":"127.0.0.1:53657_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"} current state version: 4
[junit4] 2> 152033 INFO (coreLoadExecutor-329-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ c:collection1 x:collection1] o.a.s.c.c.ZkStateReader Updating collection state at /collections/collection1/state.json from ZooKeeper...
[junit4] 2> 152033 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] o.a.s.c.o.ReplicaMutator Update state numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:53657",
[junit4] 2> "node_name":"127.0.0.1:53657_",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 152033 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] o.a.s.c.o.ReplicaMutator Collection already exists with numShards=2
[junit4] 2> 152033 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
[junit4] 2> 152036 INFO (coreLoadExecutor-329-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ c:collection1 x:collection1] o.a.s.c.c.ZkStateReader Updating data for collection1 to ver 0
[junit4] 2> 152036 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
[junit4] 2> 152037 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[A7CE6FE98D323E8F]) [n:127.0.0.1:53657_ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 152037 INFO (coreLoadExecutor-329-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ c:collection1 x:collection1] o.a.s.c.ZkController look for our core node name
[junit4] 2> 152136 INFO (OverseerStateUpdate-94030712546983939-127.0.0.1:48781_-n_0000000000) [n:127.0.0.1:48781_ ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/collection1/state.json version: 0
[junit4] 2> 152137 INFO (zkCallback-123-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 2)
[junit4] 2> 152137 INFO (zkCallback-123-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ ] o.a.s.c.c.ZkStateReader Updating data for collection1 to ver 1
[junit4] 2> 153037 INFO (coreLoadExecutor-329-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ c:collection1 x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
[junit4] 2> 153037 INFO (coreLoadExecutor-329-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ c:collection1 x:collection1] o.a.s.c.ZkController Check for collection zkNode:collection1
[junit4] 2> 153038 INFO (coreLoadExecutor-329-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ c:collection1 x:collection1] o.a.s.c.ZkController Collection zkNode exists
[junit4] 2> 153038 INFO (coreLoadExecutor-329-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ c:collection1 x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/collection1
[junit4] 2> 153039 INFO (coreLoadExecutor-329-thread-1-processing-n:127.0.0.1:53657_) [n:127.0.0.1:53657_ c:collection1 x:collection1] o.a.s.c.c.ZkStateReader path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 153039 INFO (coreLoadExecut
[...truncated too long message...]
DefaultMBeanServerInterceptor.getClassName(DefaultMBeanServerInterceptor.java:1804)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.safeGetClassName(DefaultMBeanServerInterceptor.java:1595)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.checkMBeanPermission(DefaultMBeanServerInterceptor.java:1813)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.exclusiveUnregisterMBean(DefaultMBeanServerInterceptor.java:430)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.unregisterMBean(DefaultMBeanServerInterceptor.java:415)
[junit4] 2> at com.sun.jmx.mbeanserver.JmxMBeanServer.unregisterMBean(JmxMBeanServer.java:546)
[junit4] 2> at org.apache.hadoop.metrics2.util.MBeans.unregister(MBeans.java:81)
[junit4] 2> at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.stopMBeans(MetricsSourceAdapter.java:227)
[junit4] 2> at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.stop(MetricsSourceAdapter.java:212)
[junit4] 2> at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.stopSources(MetricsSystemImpl.java:461)
[junit4] 2> at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.stop(MetricsSystemImpl.java:212)
[junit4] 2> at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.shutdown(MetricsSystemImpl.java:592)
[junit4] 2> at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.shutdownInstance(DefaultMetricsSystem.java:72)
[junit4] 2> at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.shutdown(DefaultMetricsSystem.java:68)
[junit4] 2> at org.apache.hadoop.hdfs.server.namenode.metrics.NameNodeMetrics.shutdown(NameNodeMetrics.java:145)
[junit4] 2> at org.apache.hadoop.hdfs.server.namenode.NameNode.stop(NameNode.java:822)
[junit4] 2> at org.apache.hadoop.hdfs.MiniDFSCluster.shutdown(MiniDFSCluster.java:1720)
[junit4] 2> at org.apache.hadoop.hdfs.MiniDFSCluster.shutdown(MiniDFSCluster.java:1699)
[junit4] 2> at org.apache.solr.cloud.hdfs.HdfsTestUtil.teardownClass(HdfsTestUtil.java:197)
[junit4] 2> at org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.teardownClass(HdfsCollectionsAPIDistributedZkTest.java:50)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:483)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:799)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> Caused by: java.lang.NullPointerException
[junit4] 2> at org.apache.hadoop.hdfs.server.blockmanagement.BlocksMap.size(BlocksMap.java:198)
[junit4] 2> at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager.getTotalBlocks(BlockManager.java:3291)
[junit4] 2> at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getBlocksTotal(FSNamesystem.java:6223)
[junit4] 2> ... 53 more
[junit4] 2> 1444105 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[A7CE6FE98D323E8F]-worker) [n:127.0.0.1:37681_ntce%2Fjk c:addReplicaColl s:shard1 r:core_node4 x:addReplicaColl_shard1_replica1] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> Jun 20, 2015 6:28:23 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 2 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene53): {other_tl1=FST50, range_facet_l_dv=Lucene50(blocksize=128), _version_=FST50, multiDefault=PostingsFormat(name=LuceneFixedGap), a_t=PostingsFormat(name=LuceneFixedGap), intDefault=FST50, a_i1=PostingsFormat(name=LuceneFixedGap), id=Lucene50(blocksize=128), range_facet_i_dv=PostingsFormat(name=LuceneFixedGap), text=Lucene50(blocksize=128), range_facet_l=PostingsFormat(name=LuceneFixedGap), timestamp=PostingsFormat(name=LuceneFixedGap)}, docValues:{range_facet_l_dv=DocValuesFormat(name=Memory), range_facet_i_dv=DocValuesFormat(name=Direct), timestamp=DocValuesFormat(name=Direct)}, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=es_CL, timezone=America/Cayenne
[junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.8.0_25 (64-bit)/cpus=4,threads=2,free=208105816,total=534249472
[junit4] 2> NOTE: All tests run in this JVM: [AutoCommitTest, TestCursorMarkWithoutUniqueKey, TestBinaryResponseWriter, SolrCoreCheckLockOnStartupTest, ActionThrottleTest, SpellCheckCollatorTest, TestDefaultSimilarityFactory, PrimUtilsTest, QueryParsingTest, TestDownShardTolerantSearch, SolrXmlInZkTest, RegexBoostProcessorTest, JavabinLoaderTest, TestQueryUtils, DirectSolrSpellCheckerTest, TestSolrQueryParser, OverseerRolesTest, QueryEqualityTest, TestSolrDynamicMBean, TestZkChroot, HdfsDirectoryTest, TestCopyFieldCollectionResource, OverseerTest, TestInitQParser, TestSolrQueryParserDefaultOperatorResource, SearchHandlerTest, DocValuesTest, ResponseLogComponentTest, DirectUpdateHandlerTest, TestDistribDocBasedVersion, TestExceedMaxTermLength, CleanupOldIndexTest, TestAuthorizationFramework, DistributedFacetPivotSmallTest, AnalyticsMergeStrategyTest, TestReplicationHandlerBackup, TestReload, TestSchemaNameResource, SuggesterTest, TestShortCircuitedRequests, TestSystemIdResolver, OpenExchangeRatesOrgProviderTest, TestSolrQueryParserResource, DOMUtilTest, NotRequiredUniqueKeyTest, TestCSVResponseWriter, DistribCursorPagingTest, OutOfBoxZkACLAndCredentialsProvidersTest, LeaderElectionTest, DeleteLastCustomShardedReplicaTest, DistributedQueueTest, PolyFieldTest, TestRebalanceLeaders, SoftAutoCommitTest, VMParamsZkACLAndCredentialsProvidersTest, TestUtils, OverriddenZkACLAndCredentialsProvidersTest, TestSolr4Spatial2, CustomCollectionTest, TestStressRecovery, TestXIncludeConfig, DistributedSuggestComponentTest, PathHierarchyTokenizerFactoryTest, TestNoOpRegenerator, TestRawResponseWriter, BadIndexSchemaTest, TestMaxScoreQueryParser, TestSearcherReuse, SolrIndexSplitterTest, TestMiniSolrCloudCluster, TestLuceneMatchVersion, SampleTest, FullSolrCloudDistribCmdsTest, UnloadDistributedZkTest, HdfsCollectionsAPIDistributedZkTest]
[junit4] Completed [218/512] on J2 in 358.22s, 1 test, 1 error <<< FAILURES!
[...truncated 964 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:533: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:474: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:61: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/extra-targets.xml:39: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:230: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:513: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1426: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:981: There were test failures: 512 suites, 2015 tests, 2 errors, 1 failure, 20 ignored (10 assumptions)
Total time: 177 minutes 41 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
Sending email for trigger: Failure