lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 88 - Still Failing
Date Thu, 09 Jun 2016 14:22:53 GMT
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/88/

3 tests failed.
FAILED:  org.apache.solr.cloud.RestartWhileUpdatingTest.test

Error Message:
There are still nodes recoverying - waited for 320 seconds

Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 320 seconds
	at __randomizedtesting.SeedInfo.seed([A0CEFEFED1780E70:289AC1247F846388]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:182)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:862)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForThingsToLevelOut(AbstractFullDistribZkTestBase.java:1418)
	at org.apache.solr.cloud.RestartWhileUpdatingTest.test(RestartWhileUpdatingTest.java:144)
	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:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:992)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
	at java.lang.Thread.run(Thread.java:745)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.RestartWhileUpdatingTest

Error Message:
1 thread leaked from SUITE scope at org.apache.solr.cloud.RestartWhileUpdatingTest:     1) Thread[id=3463, name=searcherExecutor-788-thread-1, state=WAITING, group=TGRP-RestartWhileUpdatingTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)         at java.lang.Thread.run(Thread.java:745)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.RestartWhileUpdatingTest: 
   1) Thread[id=3463, name=searcherExecutor-788-thread-1, state=WAITING, group=TGRP-RestartWhileUpdatingTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
	at __randomizedtesting.SeedInfo.seed([A0CEFEFED1780E70]:0)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.RestartWhileUpdatingTest

Error Message:
There are still zombie threads that couldn't be terminated:    1) Thread[id=3463, name=searcherExecutor-788-thread-1, state=WAITING, group=TGRP-RestartWhileUpdatingTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)         at java.lang.Thread.run(Thread.java:745)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   1) Thread[id=3463, name=searcherExecutor-788-thread-1, state=WAITING, group=TGRP-RestartWhileUpdatingTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
	at __randomizedtesting.SeedInfo.seed([A0CEFEFED1780E70]:0)




Build Log:
[...truncated 11380 lines...]
   [junit4] Suite: org.apache.solr.cloud.RestartWhileUpdatingTest
   [junit4]   2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/init-core-data-001
   [junit4]   2> 392166 INFO  (SUITE-RestartWhileUpdatingTest-seed#[A0CEFEFED1780E70]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 392166 INFO  (SUITE-RestartWhileUpdatingTest-seed#[A0CEFEFED1780E70]-worker) [    ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
   [junit4]   2> 392168 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 392169 INFO  (Thread-1900) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 392169 INFO  (Thread-1900) [    ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 392269 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.ZkTestServer start zk server on port:39005
   [junit4]   2> 392269 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 392270 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 392274 INFO  (zkCallback-393-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@32794ea4 name:ZooKeeperConnection Watcher:127.0.0.1:39005 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 392274 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 392274 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 392274 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /solr
   [junit4]   2> 392277 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 392277 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 392278 INFO  (zkCallback-394-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@8c7ab8b name:ZooKeeperConnection Watcher:127.0.0.1:39005/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 392279 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 392279 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 392279 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1
   [junit4]   2> 392279 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards
   [junit4]   2> 392280 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection
   [junit4]   2> 392280 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards
   [junit4]   2> 392281 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 392281 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 392282 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 392283 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml
   [junit4]   2> 392284 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 392284 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 392285 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 392285 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 392288 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 392288 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt
   [junit4]   2> 392288 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 392289 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml
   [junit4]   2> 392289 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 392289 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 392290 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 392290 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 392291 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 392291 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 392292 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 392292 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 392292 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 392292 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 392294 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 392297 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 392304 INFO  (zkCallback-396-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@34df0c99 name:ZooKeeperConnection Watcher:127.0.0.1:39005/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 392304 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 392305 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 392399 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores/collection1
   [junit4]   2> 392401 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.e.j.s.Server jetty-9.3.8.v20160314
   [junit4]   2> 392403 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5f7c0e0{/,null,AVAILABLE}
   [junit4]   2> 392418 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.e.j.s.ServerConnector Started ServerConnector@641d13cf{SSL,[ssl, http/1.1]}{127.0.0.1:35830}
   [junit4]   2> 392418 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.e.j.s.Server Started @396233ms
   [junit4]   2> 392418 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/tempDir-001/control/data, hostContext=/, hostPort=35830, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores}
   [junit4]   2> 392418 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@73d16e93
   [junit4]   2> 392418 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001'
   [junit4]   2> 392418 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 392418 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
   [junit4]   2> 392418 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 392419 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 392420 INFO  (zkCallback-397-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1c3ed555 name:ZooKeeperConnection Watcher:127.0.0.1:39005/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 392420 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 392420 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 392425 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
   [junit4]   2> 392425 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/solr.xml
   [junit4]   2> 392428 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores
   [junit4]   2> 392428 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.CoreContainer New CoreContainer 1510762499
   [junit4]   2> 392428 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001]
   [junit4]   2> 392429 WARN  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/lib
   [junit4]   2> 392429 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] 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> 392430 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 392430 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 392430 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 392430 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:39005/solr
   [junit4]   2> 392430 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.ZkController zkHost includes chroot
   [junit4]   2> 392430 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 392434 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 392434 INFO  (zkCallback-400-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@58c6920a name:ZooKeeperConnection Watcher:127.0.0.1:39005 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 392436 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 392436 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 392440 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$71/892459340@4faa9ea
   [junit4]   2> 392441 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 392441 INFO  (zkCallback-401-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@5311065d name:ZooKeeperConnection Watcher:127.0.0.1:39005/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 392441 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 392443 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
   [junit4]   2> 392444 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
   [junit4]   2> 392446 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
   [junit4]   2> 392446 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
   [junit4]   2> 392447 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
   [junit4]   2> 392449 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
   [junit4]   2> 392449 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
   [junit4]   2> 392450 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
   [junit4]   2> 392451 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.SolrZkClient makePath: /security.json
   [junit4]   2> 392451 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... 
   [junit4]   2> 392452 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.ZkStateReader Loaded cluster properties: {urlScheme=https}
   [junit4]   2> 392453 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0)
   [junit4]   2> 392458 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
   [junit4]   2> 392459 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
   [junit4]   2> 392459 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 392460 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/96041683405832197-127.0.0.1:35830_-n_0000000000
   [junit4]   2> 392460 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35830_
   [junit4]   2> 392460 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
   [junit4]   2> 392461 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.Overseer Overseer (id=96041683405832197-127.0.0.1:35830_-n_0000000000) starting
   [junit4]   2> 392461 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
   [junit4]   2> 392464 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 392477 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.Overseer Starting to work on the main queue
   [junit4]   2> 392478 INFO  (OverseerCollectionConfigSetProcessor-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations
   [junit4]   2> 392480 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35830_
   [junit4]   2> 392481 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:35830_
   [junit4]   2> 392481 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0)
   [junit4]   2> 392497 INFO  (zkCallback-401-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_    ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0])
   [junit4]   2> 392505 INFO  (zkCallback-401-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 392525 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
   [junit4]   2> 392525 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.CoreContainer No authentication plugin used.
   [junit4]   2> 392525 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores
   [junit4]   2> 392526 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, configSetProperties=configsetprops.json, collection=control_collection, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 392526 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.CorePropertiesLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores/collection1
   [junit4]   2> 392526 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.c.CorePropertiesLocator Found 1 core definitions
   [junit4]   2> 392542 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.ZkController publishing state=down
   [junit4]   2> 392542 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
   [junit4]   2> 392560 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] 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:35830",
   [junit4]   2>   "node_name":"127.0.0.1:35830_",
   [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> 392560 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] 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:35830",
   [junit4]   2>   "node_name":"127.0.0.1:35830_",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":null,
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 392562 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1
   [junit4]   2> 392562 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:35830_    ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
   [junit4]   2> 392562 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.ZkController Collection control_collection not visible yet, but flagging it so a watch is registered when it becomes visible
   [junit4]   2> 392565 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.o.ClusterStateMutator building a new cName: control_collection
   [junit4]   2> 392569 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
   [junit4]   2> 392573 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.c.ZkStateReader Deleting data for [control_collection]
   [junit4]   2> 392589 INFO  (zkCallback-401-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_    ] 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> 392649 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.ZkController look for our core node name
   [junit4]   2> 392649 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
   [junit4]   2> 392649 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.ZkController Check for collection zkNode:control_collection
   [junit4]   2> 392654 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.ZkController Collection zkNode exists
   [junit4]   2> 392654 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.c.ZkStateReader Load collection config from: [/collections/control_collection]
   [junit4]   2> 392669 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.c.ZkStateReader path=[/collections/control_collection] [configName]=[conf1] specified config exists in ZooKeeper
   [junit4]   2> 392669 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores/collection1'
   [junit4]   2> 392669 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 392669 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
   [junit4]   2> 392677 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0 
   [junit4]   2> 392693 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
   [junit4]   2> 392696 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.2.0
   [junit4]   2> 392710 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 392720 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 392847 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.s.IndexSchema default search field in schema is text
   [junit4]   2> 392848 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.s.IndexSchema unique key field: id
   [junit4]   2> 392848 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 392850 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 392863 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/configs/conf1', cwd=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1
   [junit4]   2> 392863 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection   x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 392863 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore solr.StandardDirectoryFactory
   [junit4]   2> 392869 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores/collection1/data/]
   [junit4]   2> 392870 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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@69ec3569
   [junit4]   2> 392870 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores/collection1/data
   [junit4]   2> 392870 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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-6.x/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores/collection1/data/index/
   [junit4]   2> 392871 WARN  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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-6.x/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 392871 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores/collection1/data/index
   [junit4]   2> 392871 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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=44, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=1.962890625, floorSegmentMB=1.845703125, forceMergeDeletesPctAllowed=18.166896600705904, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8813737545790643
   [junit4]   2> 392877 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 	commit{dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores/collection1/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 392877 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
   [junit4]   2> 392878 INFO  (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:35830_ 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-6.x/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores/collection1/data/
   [junit4]   2> 392880 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 392880 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 392880 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 392880 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 392880 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 392880 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392880 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392880 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392880 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392880 WARN  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,args = {defaults={a=A,b=B}}}
   [junit4]   2> 392882 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 392882 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 392883 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 392884 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 392887 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,/update/json/docs,/admin/luke,/export,/get,/admin/properties,/update/json,/admin/threads,/dump,/update/csv,/sql,/graph,/admin/segments,/admin/system,/replication,/config,/stream,/schema,/admin/plugins,/admin/logging,/admin/ping,/update,/admin/file
   [junit4]   2> 392887 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392887 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392887 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392888 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 30000ms; 
   [junit4]   2> 392888 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: if uncommited for 3000ms; 
   [junit4]   2> 392889 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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=18, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=77.4248046875, floorSegmentMB=1.3681640625, forceMergeDeletesPctAllowed=17.63879407336132, segmentsPerTier=28.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4134295805227446
   [junit4]   2> 392889 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 	commit{dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/control-001/cores/collection1/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 392889 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
   [junit4]   2> 392889 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@34fbde60[collection1] main]
   [junit4]   2> 392889 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392893 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392893 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392893 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 392893 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {}
   [junit4]   2> 392893 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392894 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392894 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392894 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
   [junit4]   2> 392894 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 392894 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392894 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392894 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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> 392894 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ 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 1536666935253532672
   [junit4]   2> 392896 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 1.0ms to seed version buckets with highest version 1536666935253532672
   [junit4]   2> 392896 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1
   [junit4]   2> 392896 INFO  (searcherExecutor-732-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@34fbde60[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 392896 INFO  (coreLoadExecutor-731-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: collection1
   [junit4]   2> 392897 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ 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:35830 collection:control_collection shard:shard1
   [junit4]   2> 392897 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ 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> 392899 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ 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/96041683405832197-core_node1-n_0000000000
   [junit4]   2> 392900 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard=shard1 and weAreReplacement=false and leaderVoteWait=300000
   [junit4]   2> 392901 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 392901 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ 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> 392901 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:35830/collection1/
   [junit4]   2> 392901 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 392901 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy https://127.0.0.1:35830/collection1/ has no replicas
   [junit4]   2> 392903 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] 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> 392903 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 392914 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/control_collection/leaders/shard1/leader after winning as /collections/control_collection/leader_elect/shard1/election/96041683405832197-core_node1-n_0000000000
   [junit4]   2> 392945 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] 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:35830",
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "state":"active"} current state version: 1
   [junit4]   2> 392948 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ 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:35830/collection1/ shard1
   [junit4]   2> 393047 INFO  (zkCallback-401-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_    ] 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> 393057 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController We are https://127.0.0.1:35830/collection1/ and leader is https://127.0.0.1:35830/collection1/
   [junit4]   2> 393058 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ 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:35830
   [junit4]   2> 393058 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 393058 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController publishing state=active
   [junit4]   2> 393058 INFO  (coreZkRegister-725-thread-1-processing-n:127.0.0.1:35830_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:35830_ 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> 393059 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] 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:35830",
   [junit4]   2>   "node_name":"127.0.0.1:35830_",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "operation":"state"} current state version: 2
   [junit4]   2> 393059 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "core_node_name":"core_node1",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:35830",
   [junit4]   2>   "node_name":"127.0.0.1:35830_",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 393063 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 393064 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 393065 INFO  (zkCallback-405-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@ab5da35 name:ZooKeeperConnection Watcher:127.0.0.1:39005/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 393065 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 393065 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 393065 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... 
   [junit4]   2> 393065 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ZkStateReader Loaded cluster properties: {urlScheme=https}
   [junit4]   2> 393066 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 393067 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 393067 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.AbstractFullDistribZkTestBase Creating collection1 with stateFormat=2
   [junit4]   2> 393067 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 393067 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 393070 INFO  (zkCallback-406-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@311bc732 name:ZooKeeperConnection Watcher:127.0.0.1:39005/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 393070 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 393070 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 393072 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"create",
   [junit4]   2>   "name":"collection1",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "stateFormat":"2"} current state version: 2
   [junit4]   2> 393072 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1
   [junit4]   2> 393077 INFO  (zkCallback-405-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> 393077 INFO  (zkCallback-401-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_    ] 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> 393180 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/collection1/state.json
   [junit4]   2> 393189 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/shard-1-001/cores/collection1
   [junit4]   2> 393189 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/shard-1-001
   [junit4]   2> 393191 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.e.j.s.Server jetty-9.3.8.v20160314
   [junit4]   2> 393191 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2878fd67{/,null,AVAILABLE}
   [junit4]   2> 393193 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.e.j.s.ServerConnector Started ServerConnector@487e3cb7{SSL,[ssl, http/1.1]}{127.0.0.1:57395}
   [junit4]   2> 393194 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.e.j.s.Server Started @397009ms
   [junit4]   2> 393194 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/, hostPort=57395, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/shard-1-001/cores}
   [junit4]   2> 393194 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@73d16e93
   [junit4]   2> 393194 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/shard-1-001'
   [junit4]   2> 393194 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 393194 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
   [junit4]   2> 393194 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 393195 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 393203 INFO  (zkCallback-407-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1e69b9fc name:ZooKeeperConnection Watcher:127.0.0.1:39005/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 393203 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 393203 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 393206 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
   [junit4]   2> 393206 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/shard-1-001/solr.xml
   [junit4]   2> 393210 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/shard-1-001/cores
   [junit4]   2> 393210 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.CoreContainer New CoreContainer 726432430
   [junit4]   2> 393210 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/shard-1-001]
   [junit4]   2> 393210 WARN  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/shard-1-001/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/shard-1-001/lib
   [junit4]   2> 393213 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] 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> 393215 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 393215 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 393215 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 393215 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:39005/solr
   [junit4]   2> 393215 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.ZkController zkHost includes chroot
   [junit4]   2> 393215 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 393215 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 393217 INFO  (zkCallback-410-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@630b7a50 name:ZooKeeperConnection Watcher:127.0.0.1:39005 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 393217 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 393217 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 393218 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$71/892459340@2b644b1e
   [junit4]   2> 393219 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 393219 INFO  (zkCallback-411-thread-1-processing-n:127.0.0.1:57395_) [n:127.0.0.1:57395_    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@77ccc98c name:ZooKeeperConnection Watcher:127.0.0.1:39005/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 393219 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 393228 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... 
   [junit4]   2> 393228 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.c.ZkStateReader Loaded cluster properties: {urlScheme=https}
   [junit4]   2> 393228 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 393230 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 393231 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/96041683405832202-127.0.0.1:57395_-n_0000000001
   [junit4]   2> 393232 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/96041683405832197-127.0.0.1:35830_-n_0000000000 to know if I could be the leader
   [junit4]   2> 393232 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.ZkController Publish node=127.0.0.1:57395_ as DOWN
   [junit4]   2> 393234 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:57395_"} current state version: 3
   [junit4]   2> 393234 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:57395_
   [junit4]   2> 393236 INFO  (zkCallback-401-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_    ] 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> 393236 INFO  (zkCallback-405-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> 393236 INFO  (zkCallback-411-thread-1-processing-n:127.0.0.1:57395_) [n:127.0.0.1:57395_    ] 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> 393341 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/collection1/state.json version: 0
   [junit4]   2> 394233 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57395_
   [junit4]   2> 394234 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:57395_
   [junit4]   2> 394235 INFO  (zkCallback-405-thread-1) [    ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1])
   [junit4]   2> 394235 INFO  (zkCallback-401-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_    ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1])
   [junit4]   2> 394235 INFO  (zkCallback-401-thread-1-processing-n:127.0.0.1:35830_) [n:127.0.0.1:35830_    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 394235 INFO  (zkCallback-405-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 394236 INFO  (zkCallback-411-thread-1-processing-n:127.0.0.1:57395_) [n:127.0.0.1:57395_    ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1])
   [junit4]   2> 394236 INFO  (zkCallback-411-thread-1-processing-n:127.0.0.1:57395_) [n:127.0.0.1:57395_    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 394253 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
   [junit4]   2> 394253 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.CoreContainer No authentication plugin used.
   [junit4]   2> 394253 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/shard-1-001/cores
   [junit4]   2> 394254 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, configSetProperties=configsetprops.json, collection=collection1, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 394254 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.CorePropertiesLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001/shard-1-001/cores/collection1
   [junit4]   2> 394254 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.c.CorePropertiesLocator Found 1 core definitions
   [junit4]   2> 394255 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1
   [junit4]   2> 394255 INFO  (TEST-RestartWhileUpdatingTest.test-seed#[A0CEFEFED1780E70]) [n:127.0.0.1:57395_    ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
   [junit4]   2> 394255 INFO  (coreLoadExecutor-742-thread-1-processing-n:127.0.0.1:57395_) [n:127.0.0.1:57395_ c:collection1   x:collection1] o.a.s.c.ZkController publishing state=down
   [junit4]   2> 394255 INFO  (coreLoadExecutor-742-thread-1-processing-n:127.0.0.1:57395_) [n:127.0.0.1:57395_ c:collection1   x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
   [junit4]   2> 394256 INFO  (coreLoadExecutor-742-thread-1-processing-n:127.0.0.1:57395_) [n:127.0.0.1:57395_ c:collection1   x:collection1] o.a.s.c.ZkController Registering watch for collection collection1
   [junit4]   2> 394257 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] 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:57395",
   [junit4]   2>   "node_name":"127.0.0.1:57395_",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":null,
   [junit4]   2>   "collection":"collection1",
   [junit4]   2>   "operation":"state"} current state version: 4
   [junit4]   2> 394257 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] 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:57395",
   [junit4]   2>   "node_name":"127.0.0.1:57395_",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":null,
   [junit4]   2>   "collection":"collection1",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 394257 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.o.ReplicaMutator Collection already exists with numShards=1
   [junit4]   2> 394257 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
   [junit4]   2> 394257 INFO  (coreLoadExecutor-742-thread-1-processing-n:127.0.0.1:57395_) [n:127.0.0.1:57395_ c:collection1   x:collection1] o.a.s.c.c.ZkStateReader Add data for [collection1] ver [1]
   [junit4]   2> 394260 INFO  (coreLoadExecutor-742-thread-1-processing-n:127.0.0.1:57395_) [n:127.0.0.1:57395_ c:collection1   x:collection1] o.a.s.c.ZkController look for our core node name
   [junit4]   2> 394361 INFO  (OverseerStateUpdate-96041683405832197-127.0.0.1:35830_-n_0000000000) [n:127.0.0.1:35830_    ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/collection1/state.json version: 1
   [junit4]   2> 394361 INFO  (zkCallback-411-thread-1-processing-n:127.0.0.1:57395_) [n:127.0.0.1:57395_    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] h

[...truncated too long message...]

 -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
   [junit4] FAILURE  491s J1 | RestartWhileUpdatingTest.test <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: There are still nodes recoverying - waited for 320 seconds
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([A0CEFEFED1780E70:289AC1247F846388]:0)
   [junit4]    > 	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:182)
   [junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:862)
   [junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForThingsToLevelOut(AbstractFullDistribZkTestBase.java:1418)
   [junit4]    > 	at org.apache.solr.cloud.RestartWhileUpdatingTest.test(RestartWhileUpdatingTest.java:144)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:992)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 883387 INFO  (SUITE-RestartWhileUpdatingTest-seed#[A0CEFEFED1780E70]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J1/temp/solr.cloud.RestartWhileUpdatingTest_A0CEFEFED1780E70-001
   [junit4]   2> Jun 09, 2016 1:51:19 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 2 leaked thread(s).
   [junit4]   2> Jun 09, 2016 1:51:39 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> SEVERE: 1 thread leaked from SUITE scope at org.apache.solr.cloud.RestartWhileUpdatingTest: 
   [junit4]   2>    1) Thread[id=3463, name=searcherExecutor-788-thread-1, state=WAITING, group=TGRP-RestartWhileUpdatingTest]
   [junit4]   2>         at sun.misc.Unsafe.park(Native Method)
   [junit4]   2>         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
   [junit4]   2>         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
   [junit4]   2>         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [junit4]   2>         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   [junit4]   2>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]   2>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2>         at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> Jun 09, 2016 1:51:39 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
   [junit4]   2> INFO: Starting to interrupt leaked threads:
   [junit4]   2>    1) Thread[id=3463, name=searcherExecutor-788-thread-1, state=WAITING, group=TGRP-RestartWhileUpdatingTest]
   [junit4]   2> Jun 09, 2016 1:51:42 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
   [junit4]   2> SEVERE: There are still zombie threads that couldn't be terminated:
   [junit4]   2>    1) Thread[id=3463, name=searcherExecutor-788-thread-1, state=WAITING, group=TGRP-RestartWhileUpdatingTest]
   [junit4]   2>         at sun.misc.Unsafe.park(Native Method)
   [junit4]   2>         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
   [junit4]   2>         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
   [junit4]   2>         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [junit4]   2>         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   [junit4]   2>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]   2>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2>         at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene60): {rnd_b=PostingsFormat(name=MockRandom), _version_=Lucene50(blocksize=128), a_t=PostingsFormat(name=Asserting), a_i=PostingsFormat(name=MockRandom), id=PostingsFormat(name=MockRandom)}, docValues:{}, maxPointsInLeafNode=642, maxMBSortInHeap=7.486758976966666, sim=RandomSimilarity(queryNorm=true,coord=no): {}, locale=pt-PT, timezone=Africa/Porto-Novo
   [junit4]   2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8.0_74 (64-bit)/cpus=4,threads=2,free=132649272,total=501219328
   [junit4]   2> NOTE: All tests run in this JVM: [ZkSolrClientTest, TestFastLRUCache, TestPartialUpdateDeduplication, DocValuesMissingTest, SpellPossibilityIteratorTest, TestLFUCache, TestAnalyzeInfixSuggestions, TestDynamicFieldResource, TestReqParamsAPI, TestQueryUtils, SortByFunctionTest, TestManagedSchemaAPI, TestConfigSetsAPIZkFailure, TestSolrDeletionPolicy2, MultiTermTest, HdfsWriteToMultipleCollectionsTest, TestInfoStreamLogging, ParsingFieldUpdateProcessorsTest, SharedFSAutoReplicaFailoverUtilsTest, TestSerializedLuceneMatchVersion, OutOfBoxZkACLAndCredentialsProvidersTest, MoreLikeThisHandlerTest, TestBlobHandler, BadCopyFieldTest, DistributedQueueTest, AsyncMigrateRouteKeyTest, TestJsonFacets, TestSolrDynamicMBean, SortSpecParsingTest, RestartWhileUpdatingTest]
   [junit4]   2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RestartWhileUpdatingTest -Dtests.seed=A0CEFEFED1780E70 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/x1/jenkins/lucene-data/enwiki.random.lines.txt -Dtests.locale=pt-PT -Dtests.timezone=Africa/Porto-Novo -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   0.00s J1 | RestartWhileUpdatingTest (suite) <<<
   [junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.RestartWhileUpdatingTest: 
   [junit4]    >    1) Thread[id=3463, name=searcherExecutor-788-thread-1, state=WAITING, group=TGRP-RestartWhileUpdatingTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
   [junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
   [junit4]    >         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]    >         at java.lang.Thread.run(Thread.java:745)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([A0CEFEFED1780E70]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=3463, name=searcherExecutor-788-thread-1, state=WAITING, group=TGRP-RestartWhileUpdatingTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
   [junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
   [junit4]    >         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]    >         at java.lang.Thread.run(Thread.java:745)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([A0CEFEFED1780E70]:0)
   [junit4] Completed [108/613 (1!)] on J1 in 514.35s, 1 test, 1 failure, 2 errors <<< FAILURES!

[...truncated 1538 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/build.xml:747: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/build.xml:684: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build.xml:233: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/common-build.xml:531: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/lucene/common-build.xml:1427: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/lucene/common-build.xml:984: There were test failures: 613 suites (10 ignored), 2567 tests, 2 suite-level errors, 1 failure, 1533 ignored (6 assumptions) [seed: A0CEFEFED1780E70]

Total time: 210 minutes 35 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any




Mime
View raw message