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-Tests-7.x - Build # 114 - Still Unstable
Date Wed, 02 Aug 2017 12:14:36 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.x/114/

5 tests failed.
FAILED:  org.apache.solr.cloud.ChaosMonkeyNothingIsSafeWithPullReplicasTest.test

Error Message:
KeeperErrorCode = Session expired for /live_nodes

Stack Trace:
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /live_nodes
	at __randomizedtesting.SeedInfo.seed([9185DC3F608BFC62:19D1E3E5CE77919A]:0)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1532)
	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:340)
	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:337)
	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:337)
	at org.apache.solr.common.cloud.ZkStateReader.refreshLiveNodes(ZkStateReader.java:673)
	at org.apache.solr.common.cloud.ZkStateReader.updateLiveNodes(ZkStateReader.java:343)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.logReplicaTypesReplicationInfo(AbstractFullDistribZkTestBase.java:2067)
	at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeWithPullReplicasTest.test(ChaosMonkeyNothingIsSafeWithPullReplicasTest.java:312)
	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:1713)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:985)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:960)
	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:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	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:368)
	at java.lang.Thread.run(Thread.java:748)


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

Error Message:
3 threads leaked from SUITE scope at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeWithPullReplicasTest:     1) Thread[id=12561, name=Connection evictor, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeWithPullReplicasTest]         at java.lang.Thread.sleep(Native Method)         at org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66)         at java.lang.Thread.run(Thread.java:748)    2) Thread[id=12724, name=zkCallback-2561-thread-2-EventThread, state=WAITING, group=TGRP-ChaosMonkeyNothingIsSafeWithPullReplicasTest]         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 org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:501)    3) Thread[id=12723, name=zkCallback-2561-thread-2-SendThread(127.0.0.1:39194), state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeWithPullReplicasTest]         at java.lang.Thread.sleep(Native Method)         at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)         at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:997)         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1060)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 3 threads leaked from SUITE scope at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeWithPullReplicasTest: 
   1) Thread[id=12561, name=Connection evictor, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeWithPullReplicasTest]
        at java.lang.Thread.sleep(Native Method)
        at org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66)
        at java.lang.Thread.run(Thread.java:748)
   2) Thread[id=12724, name=zkCallback-2561-thread-2-EventThread, state=WAITING, group=TGRP-ChaosMonkeyNothingIsSafeWithPullReplicasTest]
        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 org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:501)
   3) Thread[id=12723, name=zkCallback-2561-thread-2-SendThread(127.0.0.1:39194), state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeWithPullReplicasTest]
        at java.lang.Thread.sleep(Native Method)
        at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)
        at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:997)
        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1060)
	at __randomizedtesting.SeedInfo.seed([9185DC3F608BFC62]:0)


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

Error Message:
There are still zombie threads that couldn't be terminated:    1) Thread[id=12723, name=zkCallback-2561-thread-2-SendThread(127.0.0.1:39194), state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeWithPullReplicasTest]         at java.lang.Thread.sleep(Native Method)         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1051)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   1) Thread[id=12723, name=zkCallback-2561-thread-2-SendThread(127.0.0.1:39194), state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeWithPullReplicasTest]
        at java.lang.Thread.sleep(Native Method)
        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1051)
	at __randomizedtesting.SeedInfo.seed([9185DC3F608BFC62]:0)


FAILED:  org.apache.solr.common.cloud.TestCollectionStateWatchers.testWatchesWorkForStateFormat1

Error Message:
CollectionStateWatcher not notified of stateformat=1 collection creation

Stack Trace:
java.lang.AssertionError: CollectionStateWatcher not notified of stateformat=1 collection creation
	at __randomizedtesting.SeedInfo.seed([C3F099FC549C4D8F:A4378512A024692E]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.apache.solr.common.cloud.TestCollectionStateWatchers.testWatchesWorkForStateFormat1(TestCollectionStateWatchers.java:290)
	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:1713)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
	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:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	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:368)
	at java.lang.Thread.run(Thread.java:748)


FAILED:  org.apache.solr.TestDistributedSearch.test

Error Message:
.responseHeader.status!=warnings (unordered or missing)

Stack Trace:
junit.framework.AssertionFailedError: .responseHeader.status!=warnings (unordered or missing)
	at __randomizedtesting.SeedInfo.seed([9185DC3F608BFC62:19D1E3E5CE77919A]:0)
	at junit.framework.Assert.fail(Assert.java:50)
	at org.apache.solr.BaseDistributedSearchTestCase.compareSolrResponses(BaseDistributedSearchTestCase.java:913)
	at org.apache.solr.BaseDistributedSearchTestCase.compareResponses(BaseDistributedSearchTestCase.java:932)
	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:607)
	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:587)
	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:566)
	at org.apache.solr.TestDistributedSearch.test(TestDistributedSearch.java:241)
	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:1713)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsRepeatStatement.callStatement(BaseDistributedSearchTestCase.java:1011)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:960)
	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:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	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:368)
	at java.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 11187 lines...]
   [junit4] Suite: org.apache.solr.TestDistributedSearch
   [junit4]   2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_9185DC3F608BFC62-001/init-core-data-001
   [junit4]   2> 749657 WARN  (SUITE-TestDistributedSearch-seed#[9185DC3F608BFC62]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=35 numCloses=35
   [junit4]   2> 749658 INFO  (SUITE-TestDistributedSearch-seed#[9185DC3F608BFC62]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 749659 INFO  (SUITE-TestDistributedSearch-seed#[9185DC3F608BFC62]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=https://issues.apache.org/jira/browse/SOLR-9061)
   [junit4]   2> 749659 INFO  (SUITE-TestDistributedSearch-seed#[9185DC3F608BFC62]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 749659 INFO  (SUITE-TestDistributedSearch-seed#[9185DC3F608BFC62]-worker) [    ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /d_d/mf
   [junit4]   2> 751168 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_9185DC3F608BFC62-001/tempDir-001/control/cores/collection1
   [junit4]   2> 751169 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 751170 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@484cb5b6{/d_d/mf,null,AVAILABLE}
   [junit4]   2> 751171 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.e.j.s.AbstractConnector Started ServerConnector@63fee910{HTTP/1.1,[http/1.1]}{127.0.0.1:42055}
   [junit4]   2> 751171 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.e.j.s.Server Started @761896ms
   [junit4]   2> 751171 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/d_d/mf, hostPort=42055, coreRootDirectory=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_9185DC3F608BFC62-001/tempDir-001/control/cores}
   [junit4]   2> 751171 ERROR (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 751171 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 7.1.0
   [junit4]   2> 751172 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in standalone mode on port null
   [junit4]   2> 751172 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config dir: null
   [junit4]   2> 751172 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-08-02T09:43:30.539Z
   [junit4]   2> 751217 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_9185DC3F608BFC62-001/tempDir-001/control/solr.xml
   [junit4]   2> 751234 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@629d45d1, but no JMX reporters were configured - adding default JMX reporter.
   [junit4]   2> 751409 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@629d45d1
   [junit4]   2> 751425 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@629d45d1
   [junit4]   2> 751425 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@629d45d1
   [junit4]   2> 751426 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_9185DC3F608BFC62-001/tempDir-001/control/cores
   [junit4]   2> 751427 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 751427 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 751748 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0
   [junit4]   2> 751818 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 752227 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 752251 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from configset /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1, trusted=true
   [junit4]   2> 752251 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@629d45d1
   [junit4]   2> 752251 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 752251 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_9185DC3F608BFC62-001/tempDir-001/control/cores/collection1/data/]
   [junit4]   2> 752265 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=152671162, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 752461 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 752461 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 752462 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 752462 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 752463 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=227144569, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 752463 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1d2d4a78[collection1] main]
   [junit4]   2> 752476 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 752484 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 752579 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 752579 INFO  (searcherExecutor-1123-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 752580 INFO  (coreLoadExecutor-1122-thread-1) [    x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1574611988719337472
   [junit4]   2> 752580 INFO  (searcherExecutor-1123-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 752580 INFO  (searcherExecutor-1123-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 752580 INFO  (searcherExecutor-1123-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 752580 INFO  (searcherExecutor-1123-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 752580 INFO  (searcherExecutor-1123-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 752580 INFO  (searcherExecutor-1123-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 752581 INFO  (searcherExecutor-1123-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 752581 INFO  (searcherExecutor-1123-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 752591 INFO  (searcherExecutor-1123-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1d2d4a78[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 753184 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_9185DC3F608BFC62-001/tempDir-001/shard0/cores/collection1
   [junit4]   2> 753185 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 753208 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3203c8f1{/d_d/mf,null,AVAILABLE}
   [junit4]   2> 753208 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.e.j.s.AbstractConnector Started ServerConnector@49d87d4b{HTTP/1.1,[http/1.1]}{127.0.0.1:35089}
   [junit4]   2> 753208 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.e.j.s.Server Started @763933ms
   [junit4]   2> 753209 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/d_d/mf, hostPort=35089, coreRootDirectory=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_9185DC3F608BFC62-001/tempDir-001/shard0/cores}
   [junit4]   2> 753209 ERROR (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 753209 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 7.1.0
   [junit4]   2> 753209 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in standalone mode on port null
   [junit4]   2> 753209 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config dir: null
   [junit4]   2> 753209 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-08-02T09:43:32.576Z
   [junit4]   2> 753209 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_9185DC3F608BFC62-001/tempDir-001/shard0/solr.xml
   [junit4]   2> 753222 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@629d45d1, but no JMX reporters were configured - adding default JMX reporter.
   [junit4]   2> 753398 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@629d45d1
   [junit4]   2> 753414 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@629d45d1
   [junit4]   2> 753414 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@629d45d1
   [junit4]   2> 753428 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_9185DC3F608BFC62-001/tempDir-001/shard0/cores
   [junit4]   2> 753428 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 753428 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 753708 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0
   [junit4]   2> 753837 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 754427 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 754478 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from configset /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1, trusted=true
   [junit4]   2> 754478 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@629d45d1
   [junit4]   2> 754478 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 754478 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_9185DC3F608BFC62-001/tempDir-001/shard0/cores/collection1/data/]
   [junit4]   2> 754525 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=152671162, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 754762 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 754762 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 754775 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 754775 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 754776 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=227144569, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 754776 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3cf58242[collection1] main]
   [junit4]   2> 754777 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 754885 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 755207 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 755208 INFO  (coreLoadExecutor-1133-thread-1) [    x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1574611991474995200
   [junit4]   2> 755222 INFO  (searcherExecutor-1134-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 755250 INFO  (searcherExecutor-1134-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 755250 INFO  (searcherExecutor-1134-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 755250 INFO  (searcherExecutor-1134-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 755251 INFO  (searcherExecutor-1134-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 755251 INFO  (searcherExecutor-1134-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 755251 INFO  (searcherExecutor-1134-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 755251 INFO  (searcherExecutor-1134-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 755251 INFO  (searcherExecutor-1134-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 755253 INFO  (searcherExecutor-1134-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3cf58242[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 755604 INFO  (TEST-TestDistributedSearch.test-seed#[9185DC3F608BFC62]) [    ] o.a.s.SolrTestCaseJ4 ###Starting test
   [junit4]   2> 755639 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1574611991924834304)} 0 2
   [junit4]   2> 755694 INFO  (qtp36346173-1944) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1574611991973068800)} 0 11
   [junit4]   2> 755749 INFO  (qtp1882048682-1928) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[1 (1574611991985651712)]} 0 54
   [junit4]   2> 755879 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[1 (1574611992043323392)]} 0 128
   [junit4]   2> 755908 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[2 (1574611992179638272)]} 0 28
   [junit4]   2> 755976 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[2 (1574611992210046976)]} 0 66
   [junit4]   2> 756009 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[3 (1574611992280301568)]} 0 32
   [junit4]   2> 756023 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[3 (1574611992329584640)]} 0 0
   [junit4]   2> 756039 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[4 (1574611992345313280)]} 0 14
   [junit4]   2> 756041 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[4 (1574611992346361856)]} 0 2
   [junit4]   2> 756075 INFO  (qtp1882048682-1931) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[5 (1574611992383062016)]} 0 0
   [junit4]   2> 756076 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[5 (1574611992385159168)]} 0 0
   [junit4]   2> 756077 INFO  (qtp1882048682-1931) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[6 (1574611992386207744)]} 0 0
   [junit4]   2> 756107 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[6 (1574611992387256320)]} 0 29
   [junit4]   2> 756108 INFO  (qtp1882048682-1931) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[7 (1574611992417665024)]} 0 0
   [junit4]   2> 756109 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[7 (1574611992418713600)]} 0 0
   [junit4]   2> 756110 INFO  (qtp1882048682-1931) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[8 (1574611992419762176)]} 0 0
   [junit4]   2> 756110 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[8 (1574611992420810752)]} 0 0
   [junit4]   2> 756140 INFO  (qtp1882048682-1931) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[9 (1574611992451219456)]} 0 0
   [junit4]   2> 756141 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[9 (1574611992452268032)]} 0 0
   [junit4]   2> 756141 INFO  (qtp1882048682-1931) [    x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1574611992453316608,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 756141 INFO  (qtp1882048682-1931) [    x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@380b4bd0 commitCommandVersion:1574611992453316608
   [junit4]   2> 756641 INFO  (qtp1882048682-1931) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5763e125[collection1] main]
   [junit4]   2> 756641 INFO  (qtp1882048682-1931) [    x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 756643 INFO  (searcherExecutor-1123-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5763e125[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.1.0):C9)))}
   [junit4]   2> 756655 INFO  (qtp1882048682-1931) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 513
   [junit4]   2> 756665 INFO  (qtp36346173-1941) [    x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1574611993002770432,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 756665 INFO  (qtp36346173-1941) [    x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2e6ebfe5 commitCommandVersion:1574611993002770432
   [junit4]   2> 756793 INFO  (qtp36346173-1941) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5cb002dc[collection1] main]
   [junit4]   2> 756794 INFO  (qtp36346173-1941) [    x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 756795 INFO  (searcherExecutor-1134-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5cb002dc[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.1.0):C9)))}
   [junit4]   2> 756795 INFO  (qtp36346173-1941) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 130
   [junit4]   2> 756912 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[10 (1574611993140133888)]} 0 116
   [junit4]   2> 757017 INFO  (qtp36346173-1944) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[10 (1574611993262817280)]} 0 104
   [junit4]   2> 757081 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[11 (1574611993372917760)]} 0 63
   [junit4]   2> 757083 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[11 (1574611993440026624)]} 0 1
   [junit4]   2> 757098 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[12 (1574611993456803840)]} 0 0
   [junit4]   2> 757099 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[12 (1574611993456803840)]} 0 0
   [junit4]   2> 757100 INFO  (qtp1882048682-1928) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[13 (1574611993457852416)]} 0 0
   [junit4]   2> 757100 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[13 (1574611993458900992)]} 0 0
   [junit4]   2> 757101 INFO  (qtp1882048682-1928) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[1001 (1574611993459949568)]} 0 0
   [junit4]   2> 757115 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[1001 (1574611993473581056)]} 0 0
   [junit4]   2> 757130 INFO  (qtp1882048682-1928) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[14 (1574611993490358272)]} 0 0
   [junit4]   2> 757131 INFO  (qtp36346173-1941) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[14 (1574611993491406848)]} 0 0
   [junit4]   2> 757134 INFO  (qtp1882048682-1931) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[15 (1574611993493504000)]} 0 0
   [junit4]   2> 757163 INFO  (qtp36346173-1941) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[15 (1574611993523912704)]} 0 28
   [junit4]   2> 757163 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[16 (1574611993524961280)]} 0 0
   [junit4]   2> 757164 INFO  (qtp36346173-1941) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[16 (1574611993526009856)]} 0 0
   [junit4]   2> 757195 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[17 (1574611993526009856)]} 0 30
   [junit4]   2> 757196 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[17 (1574611993558515712)]} 0 0
   [junit4]   2> 757212 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[100 (1574611993575292928)]} 0 0
   [junit4]   2> 757212 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[100 (1574611993576341504)]} 0 0
   [junit4]   2> 757213 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[101 (1574611993577390080)]} 0 0
   [junit4]   2> 757213 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[101 (1574611993577390080)]} 0 0
   [junit4]   2> 757214 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[102 (1574611993578438656)]} 0 0
   [junit4]   2> 757215 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[102 (1574611993578438656)]} 0 0
   [junit4]   2> 757260 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[103 (1574611993609895936)]} 0 45
   [junit4]   2> 757261 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[103 (1574611993627721728)]} 0 0
   [junit4]   2> 757262 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[104 (1574611993627721728)]} 0 0
   [junit4]   2> 757262 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[104 (1574611993628770304)]} 0 0
   [junit4]   2> 757263 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[105 (1574611993629818880)]} 0 0
   [junit4]   2> 757263 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[105 (1574611993629818880)]} 0 0
   [junit4]   2> 757276 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[106 (1574611993643450368)]} 0 0
   [junit4]   2> 757277 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[106 (1574611993644498944)]} 0 0
   [junit4]   2> 757278 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[107 (1574611993644498944)]} 0 0
   [junit4]   2> 757278 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[107 (1574611993645547520)]} 0 0
   [junit4]   2> 757279 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[108 (1574611993646596096)]} 0 0
   [junit4]   2> 757280 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[108 (1574611993646596096)]} 0 0
   [junit4]   2> 757325 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[109 (1574611993647644672)]} 0 45
   [junit4]   2> 757326 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[109 (1574611993695879168)]} 0 0
   [junit4]   2> 757327 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[110 (1574611993696927744)]} 0 0
   [junit4]   2> 757328 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[110 (1574611993697976320)]} 0 0
   [junit4]   2> 757374 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[111 (1574611993699024896)]} 0 45
   [junit4]   2> 757375 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[111 (1574611993747259392)]} 0 0
   [junit4]   2> 757376 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[112 (1574611993748307968)]} 0 0
   [junit4]   2> 757377 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[112 (1574611993748307968)]} 0 0
   [junit4]   2> 757377 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[113 (1574611993749356544)]} 0 0
   [junit4]   2> 757390 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[113 (1574611993762988032)]} 0 0
   [junit4]   2> 757391 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[114 (1574611993764036608)]} 0 0
   [junit4]   2> 757392 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[114 (1574611993764036608)]} 0 0
   [junit4]   2> 757392 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[115 (1574611993765085184)]} 0 0
   [junit4]   2> 757393 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[115 (1574611993766133760)]} 0 0
   [junit4]   2> 757393 INFO  (qtp1882048682-1930) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[116 (1574611993766133760)]} 0 0
   [junit4]   2> 757423 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[116 (1574611993796542464)]} 0 28
   [junit4]   2> 757423 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[117 (1574611993797591040)]} 0 0
   [junit4]   2> 757424 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[117 (1574611993798639616)]} 0 0
   [junit4]   2> 757425 INFO  (qtp1882048682-1928) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[118 (1574611993798639616)]} 0 0
   [junit4]   2> 757425 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[118 (1574611993799688192)]} 0 0
   [junit4]   2> 757426 INFO  (qtp1882048682-1928) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[119 (1574611993800736768)]} 0 0
   [junit4]   2> 757472 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[119 (1574611993847922688)]} 0 45
   [junit4]   2> 757473 INFO  (qtp1882048682-1928) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[120 (1574611993848971264)]} 0 0
   [junit4]   2> 757473 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[120 (1574611993850019840)]} 0 0
   [junit4]   2> 757474 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[121 (1574611993851068416)]} 0 0
   [junit4]   2> 757475 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[121 (1574611993851068416)]} 0 0
   [junit4]   2> 757504 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[122 (1574611993852116992)]} 0 28
   [junit4]   2> 757504 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[122 (1574611993882525696)]} 0 0
   [junit4]   2> 757505 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[123 (1574611993883574272)]} 0 0
   [junit4]   2> 757506 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[123 (1574611993883574272)]} 0 0
   [junit4]   2> 757506 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[124 (1574611993884622848)]} 0 0
   [junit4]   2> 757507 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[124 (1574611993885671424)]} 0 0
   [junit4]   2> 757536 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[125 (1574611993885671424)]} 0 28
   [junit4]   2> 757537 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[125 (1574611993916080128)]} 0 0
   [junit4]   2> 757537 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[126 (1574611993917128704)]} 0 0
   [junit4]   2> 757538 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[126 (1574611993918177280)]} 0 0
   [junit4]   2> 757539 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[127 (1574611993918177280)]} 0 0
   [junit4]   2> 757539 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[127 (1574611993919225856)]} 0 0
   [junit4]   2> 757540 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[128 (1574611993920274432)]} 0 0
   [junit4]   2> 757569 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[128 (1574611993950683136)]} 0 0
   [junit4]   2> 757570 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[129 (1574611993950683136)]} 0 0
   [junit4]   2> 757570 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[129 (1574611993951731712)]} 0 0
   [junit4]   2> 757571 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[130 (1574611993952780288)]} 0 0
   [junit4]   2> 757571 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[130 (1574611993952780288)]} 0 0
   [junit4]   2> 757572 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[131 (1574611993953828864)]} 0 0
   [junit4]   2> 757606 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[131 (1574611993953828864)]} 0 33
   [junit4]   2> 757607 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[132 (1574611993989480448)]} 0 0
   [junit4]   2> 757607 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[132 (1574611993990529024)]} 0 0
   [junit4]   2> 757608 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[133 (1574611993991577600)]} 0 0
   [junit4]   2> 757608 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[133 (1574611993991577600)]} 0 0
   [junit4]   2> 757609 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[134 (1574611993992626176)]} 0 0
   [junit4]   2> 757610 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[134 (1574611993992626176)]} 0 0
   [junit4]   2> 757610 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[135 (1574611993993674752)]} 0 0
   [junit4]   2> 757611 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[135 (1574611993994723328)]} 0 0
   [junit4]   2> 757611 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[136 (1574611993994723328)]} 0 0
   [junit4]   2> 757612 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[136 (1574611993995771904)]} 0 0
   [junit4]   2> 757613 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[137 (1574611993995771904)]} 0 0
   [junit4]   2> 757650 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[137 (1574611993996820480)]} 0 36
   [junit4]   2> 757651 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[138 (1574611994035617792)]} 0 0
   [junit4]   2> 757652 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[138 (1574611994036666368)]} 0 0
   [junit4]   2> 757652 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[139 (1574611994037714944)]} 0 0
   [junit4]   2> 757653 INFO  (qtp36346173-1944) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[139 (1574611994038763520)]} 0 0
   [junit4]   2> 757653 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[140 (1574611994038763520)]} 0 0
   [junit4]   2> 757687 INFO  (qtp36346173-1941) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[140 (1574611994073366528)]} 0 0
   [junit4]   2> 757699 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[141 (1574611994086998016)]} 0 0
   [junit4]   2> 757703 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[141 (1574611994091192320)]} 0 0
   [junit4]   2> 757703 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[142 (1574611994091192320)]} 0 0
   [junit4]   2> 757704 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[142 (1574611994092240896)]} 0 0
   [junit4]   2> 757705 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[143 (1574611994092240896)]} 0 0
   [junit4]   2> 757705 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[143 (1574611994093289472)]} 0 0
   [junit4]   2> 757706 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[144 (1574611994094338048)]} 0 0
   [junit4]   2> 757706 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[144 (1574611994094338048)]} 0 0
   [junit4]   2> 757738 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[145 (1574611994126843904)]} 0 0
   [junit4]   2> 757739 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[145 (1574611994127892480)]} 0 0
   [junit4]   2> 757768 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[146 (1574611994158301184)]} 0 29
   [junit4]   2> 757769 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[146 (1574611994159349760)]} 0 0
   [junit4]   2> 757769 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[147 (1574611994160398336)]} 0 0
   [junit4]   2> 757770 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[147 (1574611994161446912)]} 0 0
   [junit4]   2> 757770 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[148 (1574611994161446912)]} 0 0
   [junit4]   2> 757771 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[148 (1574611994162495488)]} 0 0
   [junit4]   2> 757800 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[149 (1574611994162495488)]} 0 28
   [junit4]   2> 757801 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={wt=javabin&version=2}{add=[149 (1574611994193952768)]} 0 0
   [junit4]   2> 757801 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1574611994193952768,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 757865 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@380b4bd0 commitCommandVersion:1574611994193952768
   [junit4]   2> 757946 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2fed6096[collection1] main]
   [junit4]   2> 757968 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 757969 INFO  (searcherExecutor-1123-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2fed6096[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.1.0):C9) Uninverting(_1(7.1.0):C59)))}
   [junit4]   2> 757969 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 168
   [junit4]   2> 757970 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1574611994371162112,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 758012 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2e6ebfe5 commitCommandVersion:1574611994371162112
   [junit4]   2> 758063 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5497eb13[collection1] main]
   [junit4]   2> 758063 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 758073 INFO  (searcherExecutor-1134-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5497eb13[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.1.0):C9) Uninverting(_1(7.1.0):C59)))}
   [junit4]   2> 758076 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/d_d/mf path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 106
   [junit4]   2> 758081 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching parameter cannot be negative
   [junit4]   2> 758081 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*&distrib=false&start=-1&wt=javabin&version=2} status=400 QTime=0
   [junit4]   2> 758082 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching parameter cannot be negative
   [junit4]   2> 758082 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*&distrib=false&start=0&rows=-1&wt=javabin&version=2} status=400 QTime=0
   [junit4]   2> 758083 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&distrib=false&sort=n_ti1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
   [junit4]   2> 758114 INFO  (qtp36346173-1942) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_ti1+desc&shard.url=http://127.0.0.1:35089/d_d/mf/collection1&rows=10&version=2&q=*:*&NOW=1501667017476&isShard=true&wt=javabin} hits=68 status=0 QTime=0
   [junit4]   2> 758143 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1501667017476&ids=144,135,3,114,148,138,6,1001,118,109&isShard=true&shard.url=http://127.0.0.1:35089/d_d/mf/collection1&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 758235 INFO  (qtp36346173-1944) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&shards=http://127.0.0.1:35089/d_d/mf/collection1&sort=n_ti1+desc&wt=javabin&version=2} hits=68 status=0 QTime=125
   [junit4]   2> 758240 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&distrib=false&sort=n_ti1+asc&wt=javabin&version=2} hits=68 status=0 QTime=0
   [junit4]   2> 758369 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_ti1+asc&shard.url=http://127.0.0.1:35089/d_d/mf/collection1&rows=10&version=2&q=*:*&NOW=1501667017609&isShard=true&wt=javabin} hits=68 status=0 QTime=0
   [junit4]   2> 758371 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1501667017609&ids=132,1,133,112,124,103,137,126,107,9&isShard=true&shard.url=http://127.0.0.1:35089/d_d/mf/collection1&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 758580 INFO  (qtp36346173-1941) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&shards=http://127.0.0.1:35089/d_d/mf/collection1&sort=n_ti1+asc&wt=javabin&version=2} hits=68 status=0 QTime=338
   [junit4]   2> 758591 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&distrib=false&sort=n_f1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
   [junit4]   2> 758670 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_f1+desc&shard.url=[ff01::083]:33332/d_d/mf|http://127.0.0.1:35089/d_d/mf/collection1|[ff01::213]:33332/d_d/mf|[ff01::114]:33332/d_d/mf&rows=10&version=2&q=*:*&NOW=1501667017959&isShard=true&wt=javabin} hits=68 status=0 QTime=0
   [junit4]   2> 758672 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1501667017959&ids=12,102,147,4,16,116,139,1001,130,131&isShard=true&shard.url=[ff01::083]:33332/d_d/mf|http://127.0.0.1:35089/d_d/mf/collection1|[ff01::213]:33332/d_d/mf|[ff01::114]:33332/d_d/mf&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 758673 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&shards=[ff01::083]:33332/d_d/mf|http://127.0.0.1:35089/d_d/mf/collection1|[ff01::213]:33332/d_d/mf|[ff01::114]:33332/d_d/mf&sort=n_f1+desc&wt=javabin&version=2} hits=68 status=0 QTime=81
   [junit4]   2> 758686 INFO  (qtp1882048682-1924) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&distrib=false&sort=n_f1+asc&wt=javabin&version=2} hits=68 status=0 QTime=0
   [junit4]   2> 758687 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_f1+asc&shard.url=http://127.0.0.1:35089/d_d/mf/collection1|[ff01::114]:33332/d_d/mf|[ff01::083]:33332/d_d/mf&rows=10&version=2&q=*:*&NOW=1501667018054&isShard=true&wt=javabin} hits=68 status=0 QTime=0
   [junit4]   2> 758688 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1501667018054&ids=121,100,111,112,101,145,113,136,8,141&isShard=true&shard.url=http://127.0.0.1:35089/d_d/mf/collection1|[ff01::114]:33332/d_d/mf|[ff01::083]:33332/d_d/mf&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 758689 INFO  (qtp36346173-1942) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&shards=http://127.0.0.1:35089/d_d/mf/collection1|[ff01::114]:33332/d_d/mf|[ff01::083]:33332/d_d/mf&sort=n_f1+asc&wt=javabin&version=2} hits=68 status=0 QTime=2
   [junit4]   2> 758719 INFO  (qtp1882048682-1931) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&distrib=false&sort=n_tf1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
   [junit4]   2> 758722 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tf1+desc&shard.url=[ff01::213]:33332/d_d/mf|http://127.0.0.1:35089/d_d/mf/collection1|[ff01::083]:33332/d_d/mf&rows=10&version=2&q=*:*&NOW=1501667018087&isShard=true&wt=javabin} hits=68 status=0 QTime=0
   [junit4]   2> 758736 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1501667018087&ids=12,111,122,112,114,4,6,105,117,130&isShard=true&shard.url=[ff01::213]:33332/d_d/mf|http://127.0.0.1:35089/d_d/mf/collection1|[ff01::083]:33332/d_d/mf&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 758737 INFO  (qtp36346173-1942) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&shards=[ff01::213]:33332/d_d/mf|http://127.0.0.1:35089/d_d/mf/collection1|[ff01::083]:33332/d_d/mf&sort=n_tf1+desc&wt=javabin&version=2} hits=68 status=0 QTime=16
   [junit4]   2> 758738 INFO  (qtp1882048682-1927) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&distrib=false&sort=n_tf1+asc&wt=javabin&version=2} hits=68 status=0 QTime=0
   [junit4]   2> 758784 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tf1+asc&shard.url=[ff01::114]:33332/d_d/mf|[ff01::213]:33332/d_d/mf|http://127.0.0.1:35089/d_d/mf/collection1&rows=10&version=2&q=*:*&NOW=1501667018146&isShard=true&wt=javabin} hits=68 status=0 QTime=0
   [junit4]   2> 758787 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1501667018146&ids=132,143,144,101,113,148,17,149,129,119&isShard=true&shard.url=[ff01::114]:33332/d_d/mf|[ff01::213]:33332/d_d/mf|http://127.0.0.1:35089/d_d/mf/collection1&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 758816 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&shards=[ff01::114]:33332/d_d/mf|[ff01::213]:33332/d_d/mf|http://127.0.0.1:35089/d_d/mf/collection1&sort=n_tf1+asc&wt=javabin&version=2} hits=68 status=0 QTime=36
   [junit4]   2> 758817 INFO  (qtp1882048682-1928) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&distrib=false&sort=n_d1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
   [junit4]   2> 758829 INFO  (qtp36346173-1944) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_d1+desc&shard.url=http://127.0.0.1:35089/d_d/mf/collection1&rows=10&version=2&q=*:*&NOW=1501667018195&isShard=true&wt=javabin} hits=68 status=0 QTime=0
   [junit4]   2> 758830 INFO  (qtp36346173-1944) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1501667018195&ids=13,124,113,102,104,148,116,1001,128,142&isShard=true&shard.url=http://127.0.0.1:35089/d_d/mf/collection1&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 758831 INFO  (qtp36346173-1948) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&shards=http://127.0.0.1:35089/d_d/mf/collection1&sort=n_d1+desc&wt=javabin&version=2} hits=68 status=0 QTime=3
   [junit4]   2> 758845 INFO  (qtp1882048682-1928) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&distrib=false&sort=n_d1+asc&wt=javabin&version=2} hits=68 status=0 QTime=12
   [junit4]   2> 758846 INFO  (qtp36346173-1944) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_d1+asc&shard.url=http://127.0.0.1:35089/d_d/mf/collection1|[ff01::213]:33332/d_d/mf&rows=10&version=2&q=*:*&NOW=1501667018213&isShard=true&wt=javabin} hits=68 status=0 QTime=0
   [junit4]   2> 758847 INFO  (qtp36346173-1947) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1501667018213&ids=11,110,144,123,103,136,5,127,109,10&isShard=true&shard.url=http://127.0.0.1:35089/d_d/mf/collection1|[ff01::213]:33332/d_d/mf&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 758986 INFO  (qtp36346173-1946) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&shards=http://127.0.0.1:35089/d_d/mf/collection1|[ff01::213]:33332/d_d/mf&sort=n_d1+asc&wt=javabin&version=2} hits=68 status=0 QTime=140
   [junit4]   2> 759027 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&distrib=false&sort=n_td1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
   [junit4]   2> 759031 INFO  (qtp36346173-1942) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_td1+desc&shard.url=http://127.0.0.1:35089/d_d/mf/collection1&rows=10&version=2&q=*:*&NOW=1501667018395&isShard=true&wt=javabin} hits=68 status=0 QTime=0
   [junit4]   2> 759032 INFO  (qtp36346173-1942) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1501667018395&ids=143,121,100,112,123,103,138,17,108,120&isShard=true&shard.url=http://127.0.0.1:35089/d_d/mf/collection1&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 759033 INFO  (qtp36346173-1945) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&shards=http://127.0.0.1:35089/d_d/mf/collection1&sort=n_td1+desc&wt=javabin&version=2} hits=68 status=0 QTime=4
   [junit4]   2> 759034 INFO  (qtp1882048682-1929) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&distrib=false&sort=n_td1+asc&wt=javabin&version=2} hits=68 status=0 QTime=0
   [junit4]   2> 759047 INFO  (qtp36346173-1942) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_td1+asc&shard.url=http://127.0.0.1:35089/d_d/mf/collection1|[ff01::213]:33332/d_d/mf|[ff01::083]:33332/d_d/mf&rows=10&version=2&q=*:*&NOW=1501667018411&isShard=true&wt=javabin} hits=68 status=0 QTime=0
   [junit4]   2> 759060 INFO  (qtp36346173-1942) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1501667018411&ids=114,15,16,116,128,8,107,129,109,131&isShard=true&shard.url=http://127.0.0.1:35089/d_d/mf/collection1|[ff01::213]:33332/d_d/mf|[ff01::083]:33332/d_d/mf&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 759060 INFO  (qtp36346173-1941) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&shards=http://127.0.0.1:35089/d_d/mf/collection1|[ff01::213]:33332/d_d/mf|[ff01::083]:33332/d_d/mf&sort=n_td1+asc&wt=javabin&version=2} hits=68 status=0 QTime=16
   [junit4]   2> 759064 INFO  (qtp1882048682-1931) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&distrib=false&sort=n_l1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
   [junit4]   2> 759065 INFO  (qtp36346173-1942) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_l1+desc&shard.url=http://127.0.0.1:35089/d_d/mf/collection1|[ff01::114]:33332/d_d/mf&rows=10&version=2&q=*:*&NOW=1501667018431&isShard=true&wt=javabin} hits=68 status=0 QTime=0
   [junit4]   2> 759066 INFO  (qtp36346173-1942) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/d_d/mf path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1501667018431&ids=122,13,15,136,104,16,6,108,9,140&isShard=true&shard.url=http://127.0.0.1:35089/d_d/mf/collection1|[ff01::114

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

edicate.shard1.leader, tag=1941428810
   [junit4]   2> 149314 INFO  (coreCloseExecutor-134-thread-1) [n:127.0.0.1:45957_solr c:testcollection s:shard3 r:core_node7 x:testcollection_shard3_replica_n4] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.testcollection.shard3.leader, tag=814076487
   [junit4]   2> 149314 INFO  (coreCloseExecutor-134-thread-2) [n:127.0.0.1:45957_solr c:falsepredicate s:shard2 r:core_node6 x:falsepredicate_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.falsepredicate.shard2.replica_n2, tag=1521026937
   [junit4]   2> 149329 INFO  (coreCloseExecutor-134-thread-2) [n:127.0.0.1:45957_solr c:falsepredicate s:shard2 r:core_node6 x:falsepredicate_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.falsepredicate.shard2.leader, tag=1521026937
   [junit4]   2> 149329 INFO  (coreCloseExecutor-132-thread-1) [n:127.0.0.1:45685_solr c:stateformat1 s:shard1 r:core_node2 x:stateformat1_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.stateformat1.shard1.leader, tag=267991016
   [junit4]   2> 149330 INFO  (coreCloseExecutor-134-thread-4) [n:127.0.0.1:45957_solr c:waitforstate s:shard1 r:core_node2 x:waitforstate_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.waitforstate.shard1.replica_n1, tag=1558737015
   [junit4]   2> 149332 INFO  (coreCloseExecutor-132-thread-3) [n:127.0.0.1:45685_solr c:falsepredicate s:shard3 r:core_node7 x:falsepredicate_shard3_replica_n3] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.falsepredicate.shard3.replica_n3, tag=131335026
   [junit4]   2> 149361 INFO  (coreCloseExecutor-134-thread-4) [n:127.0.0.1:45957_solr c:waitforstate s:shard1 r:core_node2 x:waitforstate_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.waitforstate.shard1.leader, tag=1558737015
   [junit4]   2> 149366 INFO  (coreCloseExecutor-132-thread-3) [n:127.0.0.1:45685_solr c:falsepredicate s:shard3 r:core_node7 x:falsepredicate_shard3_replica_n3] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.falsepredicate.shard3.leader, tag=131335026
   [junit4]   2> 149367 INFO  (coreCloseExecutor-132-thread-2) [n:127.0.0.1:45685_solr c:testcollection s:shard2 r:core_node5 x:testcollection_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testcollection.shard2.replica_n2, tag=1468943843
   [junit4]   2> 149393 INFO  (coreCloseExecutor-134-thread-3) [n:127.0.0.1:45957_solr c:currentstate s:shard1 r:core_node2 x:currentstate_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.currentstate.shard1.replica_n1, tag=750366028
   [junit4]   2> 149427 INFO  (zkCallback-21-thread-3-processing-n:127.0.0.1:45685_solr) [n:127.0.0.1:45685_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 149442 INFO  (zkCallback-54-thread-3-processing-n:127.0.0.1:45957_solr) [n:127.0.0.1:45957_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 149442 INFO  (zkCallback-22-thread-2-processing-n:127.0.0.1:45315_solr) [n:127.0.0.1:45315_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 149442 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from client sessionid 0x15da285a975000a, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 149525 INFO  (coreCloseExecutor-134-thread-3) [n:127.0.0.1:45957_solr c:currentstate s:shard1 r:core_node2 x:currentstate_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.currentstate.shard1.leader, tag=750366028
   [junit4]   2> 149526 INFO  (coreCloseExecutor-132-thread-2) [n:127.0.0.1:45685_solr c:testcollection s:shard2 r:core_node5 x:testcollection_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.testcollection.shard2.leader, tag=1468943843
   [junit4]   2> 149609 INFO  (zkCallback-21-thread-3-processing-n:127.0.0.1:45685_solr) [n:127.0.0.1:45685_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
   [junit4]   2> 149609 INFO  (zkCallback-21-thread-2-processing-n:127.0.0.1:45685_solr) [n:127.0.0.1:45685_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
   [junit4]   2> 149750 INFO  (zkCallback-54-thread-3-processing-n:127.0.0.1:45957_solr) [n:127.0.0.1:45957_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
   [junit4]   2> 149788 INFO  (jetty-closer-3-thread-2) [    ] o.a.s.c.Overseer Overseer (id=98413461829386249-127.0.0.1:45685_solr-n_0000000000) closing
   [junit4]   2> 149788 INFO  (OverseerStateUpdate-98413461829386249-127.0.0.1:45685_solr-n_0000000000) [n:127.0.0.1:45685_solr    ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:45685_solr
   [junit4]   2> 149802 WARN  (zkCallback-54-thread-3-processing-n:127.0.0.1:45957_solr) [n:127.0.0.1:45957_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 149802 INFO  (jetty-closer-3-thread-4) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4de54642{/solr,null,UNAVAILABLE}
   [junit4]   2> 150964 WARN  (zkCallback-48-thread-1-processing-n:127.0.0.1:36493_solr) [n:127.0.0.1:36493_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 150964 WARN  (zkCallback-22-thread-2-processing-n:127.0.0.1:45315_solr) [n:127.0.0.1:45315_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 150964 INFO  (jetty-closer-3-thread-1) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@495c1745{/solr,null,UNAVAILABLE}
   [junit4]   2> 150967 INFO  (jetty-closer-3-thread-3) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7ff1880a{/solr,null,UNAVAILABLE}
   [junit4]   2> 151348 WARN  (zkCallback-21-thread-2-processing-n:127.0.0.1:45685_solr) [n:127.0.0.1:45685_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 151349 INFO  (jetty-closer-3-thread-2) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@196b32e7{/solr,null,UNAVAILABLE}
   [junit4]   2> 151390 ERROR (SUITE-TestCollectionStateWatchers-seed#[C3F099FC549C4D8F]-worker) [    ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
   [junit4]   2> 151442 INFO  (SUITE-TestCollectionStateWatchers-seed#[C3F099FC549C4D8F]-worker) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:42861 42861
   [junit4]   2> 151609 INFO  (Thread-1) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:42861 42861
   [junit4]   2> 151610 WARN  (Thread-1) [    ] o.a.s.c.ZkTestServer Watch limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2> 	8	/solr/aliases.json
   [junit4]   2> 	7	/solr/security.json
   [junit4]   2> 	7	/solr/configs/config
   [junit4]   2> 	3	/solr/collections/stateformat1/state.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2> 	65	/solr/collections/falsepredicate/state.json
   [junit4]   2> 	53	/solr/collections/testcollection/state.json
   [junit4]   2> 	19	/solr/collections/waitforstate/state.json
   [junit4]   2> 	8	/solr/collections/currentstate/state.json
   [junit4]   2> 	8	/solr/clusterprops.json
   [junit4]   2> 	8	/solr/collections/delayed/state.json
   [junit4]   2> 	8	/solr/clusterstate.json
   [junit4]   2> 	7	/solr/collections/tobedeleted/state.json
   [junit4]   2> 	3	/solr/overseer_elect/election/98413461829386249-127.0.0.1:45685_solr-n_0000000000
   [junit4]   2> 	2	/solr/overseer_elect/election/98413461829386252-127.0.0.1:33941_solr-n_0000000001
   [junit4]   2> 	2	/solr/overseer_elect/election/98413461829386250-127.0.0.1:45315_solr-n_0000000003
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2> 	8	/solr/collections
   [junit4]   2> 	5	/solr/live_nodes
   [junit4]   2> 
   [junit4]   2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.common.cloud.TestCollectionStateWatchers_C3F099FC549C4D8F-001
   [junit4]   2> Aug 02, 2017 10:39:57 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1082, maxMBSortInHeap=6.51627230346857, sim=RandomSimilarity(queryNorm=true): {}, locale=es-VE, timezone=Canada/Yukon
   [junit4]   2> NOTE: Linux 4.4.0-83-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=4,threads=1,free=254849560,total=342884352
   [junit4]   2> NOTE: All tests run in this JVM: [TestCollectionStateWatchers]
   [junit4] Completed [25/135 (1!)] on J0 in 161.53s, 9 tests, 1 failure <<< FAILURES!

[...truncated 42829 lines...]

Mime
View raw message