You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2018/04/12 09:37:36 UTC

[JENKINS] Lucene-Solr-Tests-master - Build # 2485 - Failure

Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/2485/

4 tests failed.
FAILED:  org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testTrigger

Error Message:
waitFor not elapsed but produced an event

Stack Trace:
java.lang.AssertionError: waitFor not elapsed but produced an event
	at __randomizedtesting.SeedInfo.seed([EE2C68D3A3C4BEC6:8DE75E513A0BCDEB]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.junit.Assert.assertNull(Assert.java:551)
	at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testTrigger(IndexSizeTriggerTest.java:177)
	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:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	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:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	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.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration

Error Message:


Stack Trace:
java.util.concurrent.TimeoutException
	at __randomizedtesting.SeedInfo.seed([EE2C68D3A3C4BEC6:D7A2D1938C3B7738]:0)
	at org.apache.solr.cloud.CloudTestUtils.waitForState(CloudTestUtils.java:109)
	at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration(IndexSizeTriggerTest.java:296)
	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:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	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:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	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.cloud.autoscaling.IndexSizeTriggerTest.testMergeIntegration

Error Message:
did not finish processing in time

Stack Trace:
java.lang.AssertionError: did not finish processing in time
	at __randomizedtesting.SeedInfo.seed([EE2C68D3A3C4BEC6:BD952A6341D52B3C]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testMergeIntegration(IndexSizeTriggerTest.java:401)
	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:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	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:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	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.handler.admin.AutoscalingHistoryHandlerTest.testHistory

Error Message:
expected:<8> but was:<9>

Stack Trace:
java.lang.AssertionError: expected:<8> but was:<9>
	at __randomizedtesting.SeedInfo.seed([EE2C68D3A3C4BEC6:83D0CC2E198C41C1]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.junit.Assert.assertEquals(Assert.java:456)
	at org.apache.solr.handler.admin.AutoscalingHistoryHandlerTest.testHistory(AutoscalingHistoryHandlerTest.java:355)
	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:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	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:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	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 12664 lines...]
   [junit4] Suite: org.apache.solr.handler.admin.AutoscalingHistoryHandlerTest
   [junit4]   2> 1048099 INFO  (SUITE-AutoscalingHistoryHandlerTest-seed#[EE2C68D3A3C4BEC6]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_EE2C68D3A3C4BEC6-001/init-core-data-001
   [junit4]   2> 1048100 WARN  (SUITE-AutoscalingHistoryHandlerTest-seed#[EE2C68D3A3C4BEC6]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=2 numCloses=2
   [junit4]   2> 1048100 INFO  (SUITE-AutoscalingHistoryHandlerTest-seed#[EE2C68D3A3C4BEC6]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 1048134 INFO  (SUITE-AutoscalingHistoryHandlerTest-seed#[EE2C68D3A3C4BEC6]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 1048134 INFO  (SUITE-AutoscalingHistoryHandlerTest-seed#[EE2C68D3A3C4BEC6]-worker) [    ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_EE2C68D3A3C4BEC6-001/tempDir-001
   [junit4]   2> 1048134 INFO  (SUITE-AutoscalingHistoryHandlerTest-seed#[EE2C68D3A3C4BEC6]-worker) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 1048135 INFO  (Thread-2259) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1048135 INFO  (Thread-2259) [    ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 1048166 ERROR (Thread-2259) [    ] 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> 1048255 INFO  (SUITE-AutoscalingHistoryHandlerTest-seed#[EE2C68D3A3C4BEC6]-worker) [    ] o.a.s.c.ZkTestServer start zk server on port:34960
   [junit4]   2> 1048302 INFO  (zkConnectionManagerCallback-667-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1048320 INFO  (jetty-launcher-664-thread-1) [    ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T21:27:37Z, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 1048320 INFO  (jetty-launcher-664-thread-2) [    ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T21:27:37Z, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 1048370 INFO  (jetty-launcher-664-thread-2) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 1048370 INFO  (jetty-launcher-664-thread-2) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 1048370 INFO  (jetty-launcher-664-thread-2) [    ] o.e.j.s.session Scavenging every 600000ms
   [junit4]   2> 1048370 INFO  (jetty-launcher-664-thread-1) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 1048370 INFO  (jetty-launcher-664-thread-1) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 1048370 INFO  (jetty-launcher-664-thread-1) [    ] o.e.j.s.session Scavenging every 600000ms
   [junit4]   2> 1048370 INFO  (jetty-launcher-664-thread-2) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@49bedd6a{/solr,null,AVAILABLE}
   [junit4]   2> 1048370 INFO  (jetty-launcher-664-thread-1) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@54e9db2{/solr,null,AVAILABLE}
   [junit4]   2> 1048371 INFO  (jetty-launcher-664-thread-2) [    ] o.e.j.s.AbstractConnector Started ServerConnector@16527220{HTTP/1.1,[http/1.1]}{127.0.0.1:40647}
   [junit4]   2> 1048371 INFO  (jetty-launcher-664-thread-1) [    ] o.e.j.s.AbstractConnector Started ServerConnector@59ec5dd8{HTTP/1.1,[http/1.1]}{127.0.0.1:42529}
   [junit4]   2> 1048371 INFO  (jetty-launcher-664-thread-2) [    ] o.e.j.s.Server Started @1048642ms
   [junit4]   2> 1048371 INFO  (jetty-launcher-664-thread-1) [    ] o.e.j.s.Server Started @1048642ms
   [junit4]   2> 1048371 INFO  (jetty-launcher-664-thread-2) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40647}
   [junit4]   2> 1048371 INFO  (jetty-launcher-664-thread-1) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42529}
   [junit4]   2> 1048371 ERROR (jetty-launcher-664-thread-1) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 1048371 ERROR (jetty-launcher-664-thread-2) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 1048371 INFO  (jetty-launcher-664-thread-1) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 1048372 INFO  (jetty-launcher-664-thread-2) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 1048372 INFO  (jetty-launcher-664-thread-1) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 8.0.0
   [junit4]   2> 1048372 INFO  (jetty-launcher-664-thread-2) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 8.0.0
   [junit4]   2> 1048372 INFO  (jetty-launcher-664-thread-1) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1048372 INFO  (jetty-launcher-664-thread-2) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1048372 INFO  (jetty-launcher-664-thread-1) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1048372 INFO  (jetty-launcher-664-thread-2) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1048372 INFO  (jetty-launcher-664-thread-1) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-04-12T07:54:43.723Z
   [junit4]   2> 1048372 INFO  (jetty-launcher-664-thread-2) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-04-12T07:54:43.723Z
   [junit4]   2> 1048396 INFO  (zkConnectionManagerCallback-669-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1048447 INFO  (jetty-launcher-664-thread-2) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1048450 INFO  (zkConnectionManagerCallback-671-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1048491 INFO  (jetty-launcher-664-thread-1) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1048558 INFO  (jetty-launcher-664-thread-1) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34960/solr
   [junit4]   2> 1048594 INFO  (jetty-launcher-664-thread-2) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34960/solr
   [junit4]   2> 1048653 INFO  (zkConnectionManagerCallback-675-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1048830 INFO  (zkConnectionManagerCallback-679-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1048858 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1015d1c04180004, likely client has closed socket
   [junit4]   2> 1048909 INFO  (zkConnectionManagerCallback-681-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1048939 INFO  (zkConnectionManagerCallback-683-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1049529 INFO  (jetty-launcher-664-thread-2) [n:127.0.0.1:40647_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1049530 INFO  (jetty-launcher-664-thread-2) [n:127.0.0.1:40647_solr    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:40647_solr
   [junit4]   2> 1049600 INFO  (jetty-launcher-664-thread-2) [n:127.0.0.1:40647_solr    ] o.a.s.c.Overseer Overseer (id=72441443923787782-127.0.0.1:40647_solr-n_0000000000) starting
   [junit4]   2> 1049600 INFO  (jetty-launcher-664-thread-1) [n:127.0.0.1:42529_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1049602 INFO  (jetty-launcher-664-thread-1) [n:127.0.0.1:42529_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42529_solr
   [junit4]   2> 1049623 INFO  (zkCallback-682-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 1049641 INFO  (zkCallback-680-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 1049693 INFO  (zkConnectionManagerCallback-692-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1049695 INFO  (jetty-launcher-664-thread-2) [n:127.0.0.1:40647_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 1049696 INFO  (jetty-launcher-664-thread-2) [n:127.0.0.1:40647_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34960/solr ready
   [junit4]   2> 1049697 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.Overseer Starting to work on the main queue
   [junit4]   2> 1049698 DEBUG (OverseerAutoScalingTriggerThread-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
   [junit4]   2> 1049718 DEBUG (OverseerAutoScalingTriggerThread-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
   [junit4]   2> 1049719 INFO  (jetty-launcher-664-thread-2) [n:127.0.0.1:40647_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 1049719 INFO  (jetty-launcher-664-thread-2) [n:127.0.0.1:40647_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40647_solr
   [junit4]   2> 1049719 DEBUG (OverseerAutoScalingTriggerThread-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
   [junit4]   2> 1049719 DEBUG (OverseerAutoScalingTriggerThread-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
   [junit4]   2> 1049738 INFO  (zkCallback-691-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 1049752 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:40647_solr"} current state version: 0
   [junit4]   2> 1049752 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:40647_solr
   [junit4]   2> 1049752 INFO  (zkCallback-682-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 1049752 INFO  (zkCallback-680-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 1049772 DEBUG (OverseerAutoScalingTriggerThread-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:40647_solr, 127.0.0.1:42529_solr]
   [junit4]   2> 1049773 DEBUG (OverseerAutoScalingTriggerThread-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 1049773 DEBUG (OverseerAutoScalingTriggerThread-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 1049773 DEBUG (ScheduledTrigger-1082-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1050014 INFO  (jetty-launcher-664-thread-1) [n:127.0.0.1:42529_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42529.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@14c0e780
   [junit4]   2> 1050036 INFO  (jetty-launcher-664-thread-1) [n:127.0.0.1:42529_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42529.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@14c0e780
   [junit4]   2> 1050037 INFO  (jetty-launcher-664-thread-1) [n:127.0.0.1:42529_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42529.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@14c0e780
   [junit4]   2> 1050038 INFO  (jetty-launcher-664-thread-1) [n:127.0.0.1:42529_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_EE2C68D3A3C4BEC6-001/tempDir-001/node1/.
   [junit4]   2> 1050111 INFO  (zkConnectionManagerCallback-697-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1050113 INFO  (jetty-launcher-664-thread-1) [n:127.0.0.1:42529_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 1050113 INFO  (jetty-launcher-664-thread-1) [n:127.0.0.1:42529_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34960/solr ready
   [junit4]   2> 1050779 INFO  (jetty-launcher-664-thread-2) [n:127.0.0.1:40647_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40647.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@14c0e780
   [junit4]   2> 1050798 DEBUG (ScheduledTrigger-1082-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1050803 INFO  (jetty-launcher-664-thread-2) [n:127.0.0.1:40647_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40647.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@14c0e780
   [junit4]   2> 1050803 INFO  (jetty-launcher-664-thread-2) [n:127.0.0.1:40647_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40647.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@14c0e780
   [junit4]   2> 1050804 INFO  (jetty-launcher-664-thread-2) [n:127.0.0.1:40647_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_EE2C68D3A3C4BEC6-001/tempDir-001/node2/.
   [junit4]   2> 1050904 INFO  (zkConnectionManagerCallback-699-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1050906 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1015d1c04180009, likely client has closed socket
   [junit4]   2> 1050917 INFO  (zkConnectionManagerCallback-704-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1050918 INFO  (SUITE-AutoscalingHistoryHandlerTest-seed#[EE2C68D3A3C4BEC6]-worker) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 1050919 INFO  (SUITE-AutoscalingHistoryHandlerTest-seed#[EE2C68D3A3C4BEC6]-worker) [    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34960/solr ready
   [junit4]   2> 1050936 INFO  (qtp695522602-4173) [n:127.0.0.1:40647_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&name=.system&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=127.0.0.1:42529_solr&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 1050957 INFO  (OverseerThreadFactory-1084-thread-1) [    ] o.a.s.c.a.c.CreateCollectionCmd Create collection .system
   [junit4]   2> 1050980 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "name":".system",
   [junit4]   2>   "fromApi":"true",
   [junit4]   2>   "replicationFactor":"1",
   [junit4]   2>   "numShards":1,
   [junit4]   2>   "createNodeSet":"127.0.0.1:42529_solr",
   [junit4]   2>   "nrtReplicas":"1",
   [junit4]   2>   "stateFormat":"2",
   [junit4]   2>   "operation":"create"} current state version: 0
   [junit4]   2> 1050980 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
   [junit4]   2> 1050981 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/.system/state.json
   [junit4]   2> 1051131 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":".system",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":".system_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:42529/solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} current state version: 0
   [junit4]   2> 1051132 INFO  (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":".system",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":".system_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:42529/solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 1051133 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "replicas":{}}
   [junit4]   2> 1051133 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator New Slice: shard1:{
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "replicas":{"core_node2":{
   [junit4]   2>       "core":".system_shard1_replica_n1",
   [junit4]   2>       "base_url":"http://127.0.0.1:42529/solr",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "node_name":null,
   [junit4]   2>       "type":"NRT"}}}
   [junit4]   2> 1051233 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/.system/state.json version: 0
   [junit4]   2> 1051322 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1051322 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 1051326 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "core":".system_shard1_replica_n1",
   [junit4]   2>   "core_node_name":"core_node2",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:42529/solr",
   [junit4]   2>   "node_name":"127.0.0.1:42529_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":".system",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 1051326 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
   [junit4]   2>   "core":".system_shard1_replica_n1",
   [junit4]   2>   "core_node_name":"core_node2",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:42529/solr",
   [junit4]   2>   "node_name":"127.0.0.1:42529_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":".system",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 1051326 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node2:{"core":".system_shard1_replica_n1","base_url":"http://127.0.0.1:42529/solr","node_name":"127.0.0.1:42529_solr","state":"down","type":"NRT"}
   [junit4]   2> 1051326 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(.system//collections/.system/state.json/1)={
   [junit4]   2>   "pullReplicas":"0",
   [junit4]   2>   "replicationFactor":"1",
   [junit4]   2>   "router":{"name":"compositeId"},
   [junit4]   2>   "maxShardsPerNode":"1",
   [junit4]   2>   "autoAddReplicas":"false",
   [junit4]   2>   "nrtReplicas":"1",
   [junit4]   2>   "tlogReplicas":"0",
   [junit4]   2>   "shards":{"shard1":{
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "replicas":{"core_node2":{
   [junit4]   2>           "core":".system_shard1_replica_n1",
   [junit4]   2>           "base_url":"http://127.0.0.1:42529/solr",
   [junit4]   2>           "node_name":"127.0.0.1:42529_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT"}}}}}
   [junit4]   2> 1051427 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/.system/state.json version: 1
   [junit4]   2> 1051427 INFO  (zkCallback-680-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 1051427 INFO  (zkCallback-680-thread-2) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 1051801 DEBUG (ScheduledTrigger-1082-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1052372 WARN  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.Config You should not use LATEST as luceneMatchVersion property: if you use this setting, and then Solr upgrades to a newer release of Lucene, sizable changes may happen. If precise back compatibility is important then you should instead explicitly specify an actual Lucene version.
   [junit4]   2> 1052387 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 1052403 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
   [junit4]   2> 1052405 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
   [junit4]   2> 1052418 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
   [junit4]   2> 1052433 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/.system/managed-schema
   [junit4]   2> 1052435 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/.system/schema.xml to /configs/.system/schema.xml.bak
   [junit4]   2> 1052435 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n1' using configuration from collection .system, trusted=true
   [junit4]   2> 1052436 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42529.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@14c0e780
   [junit4]   2> 1052437 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 1052437 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SolrCore [[.system_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_EE2C68D3A3C4BEC6-001/tempDir-001/node1/.system_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_EE2C68D3A3C4BEC6-001/tempDir-001/node1/./.system_shard1_replica_n1/data/]
   [junit4]   2> 1052639 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 1052639 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1052640 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommited docs 
   [junit4]   2> 1052640 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1052655 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@52590cbb[.system_shard1_replica_n1] main]
   [junit4]   2> 1052656 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system
   [junit4]   2> 1052656 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system
   [junit4]   2> 1052656 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema
   [junit4]   2> 1052657 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
   [junit4]   2> 1052657 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 1052667 INFO  (searcherExecutor-1089-thread-1-processing-n:127.0.0.1:42529_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node2) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@52590cbb[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1052667 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1597526180383162368
   [junit4]   2> 1052672 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node2=0}, version=0}
   [junit4]   2> 1052687 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 1052687 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 1052687 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:42529/solr/.system_shard1_replica_n1/
   [junit4]   2> 1052687 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 1052687 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:42529/solr/.system_shard1_replica_n1/ has no replicas
   [junit4]   2> 1052687 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
   [junit4]   2> 1052698 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:42529/solr/.system_shard1_replica_n1/ shard1
   [junit4]   2> 1052708 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"leader",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":".system",
   [junit4]   2>   "base_url":"http://127.0.0.1:42529/solr",
   [junit4]   2>   "core":".system_shard1_replica_n1",
   [junit4]   2>   "state":"active"} current state version: 0
   [junit4]   2> 1052801 DEBUG (ScheduledTrigger-1082-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1052814 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/.system/state.json version: 2
   [junit4]   2> 1052836 INFO  (zkCallback-680-thread-2) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 1052836 INFO  (zkCallback-680-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 1052859 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 1052861 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "core":".system_shard1_replica_n1",
   [junit4]   2>   "core_node_name":"core_node2",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:42529/solr",
   [junit4]   2>   "node_name":"127.0.0.1:42529_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":".system",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 1052861 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
   [junit4]   2>   "core":".system_shard1_replica_n1",
   [junit4]   2>   "core_node_name":"core_node2",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:42529/solr",
   [junit4]   2>   "node_name":"127.0.0.1:42529_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":".system",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 1052861 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node2:{"core":".system_shard1_replica_n1","base_url":"http://127.0.0.1:42529/solr","node_name":"127.0.0.1:42529_solr","state":"active","type":"NRT","leader":"true"}
   [junit4]   2> 1052861 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(.system//collections/.system/state.json/3)={
   [junit4]   2>   "pullReplicas":"0",
   [junit4]   2>   "replicationFactor":"1",
   [junit4]   2>   "router":{"name":"compositeId"},
   [junit4]   2>   "maxShardsPerNode":"1",
   [junit4]   2>   "autoAddReplicas":"false",
   [junit4]   2>   "nrtReplicas":"1",
   [junit4]   2>   "tlogReplicas":"0",
   [junit4]   2>   "shards":{"shard1":{
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "replicas":{"core_node2":{
   [junit4]   2>           "core":".system_shard1_replica_n1",
   [junit4]   2>           "base_url":"http://127.0.0.1:42529/solr",
   [junit4]   2>           "node_name":"127.0.0.1:42529_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "leader":"true"}}}}}
   [junit4]   2> 1052861 INFO  (qtp488934169-4175) [n:127.0.0.1:42529_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1539
   [junit4]   2> 1052883 INFO  (qtp695522602-4173) [n:127.0.0.1:40647_solr    ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
   [junit4]   2> 1052958 INFO  (OverseerCollectionConfigSetProcessor-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist.  Requestor may have disconnected from ZooKeeper
   [junit4]   2> 1052962 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/.system/state.json version: 3
   [junit4]   2> 1052962 INFO  (zkCallback-680-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 1052962 INFO  (zkCallback-680-thread-2) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 1053801 DEBUG (ScheduledTrigger-1082-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1053886 INFO  (qtp695522602-4173) [n:127.0.0.1:40647_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&name=.system&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=127.0.0.1:42529_solr&wt=javabin&version=2} status=0 QTime=2950
   [junit4]   2> 1053888 INFO  (qtp695522602-4176) [n:127.0.0.1:40647_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=3&maxShardsPerNode=3&name=AutoscalingHistoryHandlerTest_collection&nrtReplicas=3&action=CREATE&numShards=1&createNodeSet=127.0.0.1:40647_solr&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 1053901 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.a.c.CreateCollectionCmd Create collection AutoscalingHistoryHandlerTest_collection
   [junit4]   2> 1053901 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/protwords.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/protwords.txt
   [junit4]   2> 1053903 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/managed-schema to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/managed-schema
   [junit4]   2> 1053905 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/solrconfig.xml to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/solrconfig.xml
   [junit4]   2> 1053907 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/synonyms.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/synonyms.txt
   [junit4]   2> 1053908 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/stopwords.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/stopwords.txt
   [junit4]   2> 1053910 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/params.json to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/params.json
   [junit4]   2> 1053912 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_it.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/contractions_it.txt
   [junit4]   2> 1053921 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_no.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_no.txt
   [junit4]   2> 1053923 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hy.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_hy.txt
   [junit4]   2> 1053924 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stemdict_nl.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stemdict_nl.txt
   [junit4]   2> 1053926 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_ca.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/contractions_ca.txt
   [junit4]   2> 1053927 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_id.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_id.txt
   [junit4]   2> 1053929 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ga.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ga.txt
   [junit4]   2> 1053931 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_da.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_da.txt
   [junit4]   2> 1053932 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hi.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_hi.txt
   [junit4]   2> 1054087 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ja.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ja.txt
   [junit4]   2> 1054343 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_pt.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_pt.txt
   [junit4]   2> 1054361 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hu.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_hu.txt
   [junit4]   2> 1054363 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_el.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_el.txt
   [junit4]   2> 1054369 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ru.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ru.txt
   [junit4]   2> 1054370 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_tr.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_tr.txt
   [junit4]   2> 1054372 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ar.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ar.txt
   [junit4]   2> 1054373 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/userdict_ja.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/userdict_ja.txt
   [junit4]   2> 1054375 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_it.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_it.txt
   [junit4]   2> 1054389 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_eu.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_eu.txt
   [junit4]   2> 1054390 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_cz.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_cz.txt
   [junit4]   2> 1054391 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stoptags_ja.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stoptags_ja.txt
   [junit4]   2> 1054405 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_fr.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/contractions_fr.txt
   [junit4]   2> 1054407 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fa.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_fa.txt
   [junit4]   2> 1054408 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_de.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_de.txt
   [junit4]   2> 1054409 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_ga.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/contractions_ga.txt
   [junit4]   2> 1054411 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ca.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ca.txt
   [junit4]   2> 1054412 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_nl.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_nl.txt
   [junit4]   2> 1054422 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_bg.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_bg.txt
   [junit4]   2> 1054423 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_es.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_es.txt
   [junit4]   2> 1054424 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_en.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_en.txt
   [junit4]   2> 1054445 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_lv.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_lv.txt
   [junit4]   2> 1054447 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_th.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_th.txt
   [junit4]   2> 1054449 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ro.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ro.txt
   [junit4]   2> 1054450 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fr.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_fr.txt
   [junit4]   2> 1054452 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_sv.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_sv.txt
   [junit4]   2> 1054453 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fi.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_fi.txt
   [junit4]   2> 1054454 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/hyphenations_ga.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/hyphenations_ga.txt
   [junit4]   2> 1054456 INFO  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_gl.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_gl.txt
   [junit4]   2> 1054466 WARN  (OverseerThreadFactory-1084-thread-2) [    ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 3 on collection AutoscalingHistoryHandlerTest_collection is higher than the number of Solr instances currently live or live and part of your createNodeSet(1). It's unusual to run two replica of the same slice on the same Solr-instance.
   [junit4]   2> 1054492 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "name":"AutoscalingHistoryHandlerTest_collection",
   [junit4]   2>   "fromApi":"true",
   [junit4]   2>   "replicationFactor":"3",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "maxShardsPerNode":"3",
   [junit4]   2>   "createNodeSet":"127.0.0.1:40647_solr",
   [junit4]   2>   "nrtReplicas":"3",
   [junit4]   2>   "stateFormat":"2",
   [junit4]   2>   "operation":"create"} current state version: 0
   [junit4]   2> 1054492 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ClusterStateMutator building a new cName: AutoscalingHistoryHandlerTest_collection
   [junit4]   2> 1054593 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/AutoscalingHistoryHandlerTest_collection/state.json
   [junit4]   2> 1054718 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"AutoscalingHistoryHandlerTest_collection",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} current state version: 0
   [junit4]   2> 1054718 INFO  (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"AutoscalingHistoryHandlerTest_collection",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 1054719 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "replicas":{}}
   [junit4]   2> 1054719 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator New Slice: shard1:{
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "replicas":{"core_node3":{
   [junit4]   2>       "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
   [junit4]   2>       "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "node_name":null,
   [junit4]   2>       "type":"NRT"}}}
   [junit4]   2> 1054720 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"AutoscalingHistoryHandlerTest_collection",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} current state version: 0
   [junit4]   2> 1054720 INFO  (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"AutoscalingHistoryHandlerTest_collection",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 1054721 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "replicas":{"core_node3":{
   [junit4]   2>       "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
   [junit4]   2>       "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "node_name":null,
   [junit4]   2>       "type":"NRT"}}}
   [junit4]   2> 1054721 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator New Slice: shard1:{
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "replicas":{
   [junit4]   2>     "core_node3":{
   [junit4]   2>       "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
   [junit4]   2>       "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "node_name":null,
   [junit4]   2>       "type":"NRT"},
   [junit4]   2>     "core_node5":{
   [junit4]   2>       "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
   [junit4]   2>       "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "node_name":null,
   [junit4]   2>       "type":"NRT"}}}
   [junit4]   2> 1054734 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.Overseer processMessage: queueSize: 3, message = {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"AutoscalingHistoryHandlerTest_collection",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} current state version: 0
   [junit4]   2> 1054734 INFO  (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"AutoscalingHistoryHandlerTest_collection",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 1054735 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "replicas":{
   [junit4]   2>     "core_node3":{
   [junit4]   2>       "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
   [junit4]   2>       "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "node_name":null,
   [junit4]   2>       "type":"NRT"},
   [junit4]   2>     "core_node5":{
   [junit4]   2>       "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
   [junit4]   2>       "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "node_name":null,
   [junit4]   2>       "type":"NRT"}}}
   [junit4]   2> 1054735 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator New Slice: shard1:{
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "replicas":{
   [junit4]   2>     "core_node3":{
   [junit4]   2>       "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
   [junit4]   2>       "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "node_name":null,
   [junit4]   2>       "type":"NRT"},
   [junit4]   2>     "core_node5":{
   [junit4]   2>       "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
   [junit4]   2>       "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "node_name":null,
   [junit4]   2>       "type":"NRT"},
   [junit4]   2>     "core_node6":{
   [junit4]   2>       "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
   [junit4]   2>       "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "node_name":null,
   [junit4]   2>       "type":"NRT"}}}
   [junit4]   2> 1054802 DEBUG (ScheduledTrigger-1082-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1054836 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/AutoscalingHistoryHandlerTest_collection/state.json version: 0
   [junit4]   2> 1054975 INFO  (qtp695522602-4182) [n:127.0.0.1:40647_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=AutoscalingHistoryHandlerTest_collection.AUTOCREATED&newCollection=true&name=AutoscalingHistoryHandlerTest_collection_shard1_replica_n1&action=CREATE&numShards=1&collection=AutoscalingHistoryHandlerTest_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1054975 INFO  (qtp695522602-4178) [n:127.0.0.1:40647_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=AutoscalingHistoryHandlerTest_collection.AUTOCREATED&newCollection=true&name=AutoscalingHistoryHandlerTest_collection_shard1_replica_n2&action=CREATE&numShards=1&collection=AutoscalingHistoryHandlerTest_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1054976 INFO  (qtp695522602-4180) [n:127.0.0.1:40647_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node6&collection.configName=AutoscalingHistoryHandlerTest_collection.AUTOCREATED&newCollection=true&name=AutoscalingHistoryHandlerTest_collection_shard1_replica_n4&action=CREATE&numShards=1&collection=AutoscalingHistoryHandlerTest_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1055023 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
   [junit4]   2>   "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
   [junit4]   2>   "core_node_name":"core_node6",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>   "node_name":"127.0.0.1:40647_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"AutoscalingHistoryHandlerTest_collection",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 1055023 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
   [junit4]   2>   "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
   [junit4]   2>   "core_node_name":"core_node6",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>   "node_name":"127.0.0.1:40647_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"AutoscalingHistoryHandlerTest_collection",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 1055023 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node6:{"core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4","base_url":"http://127.0.0.1:40647/solr","node_name":"127.0.0.1:40647_solr","state":"down","type":"NRT"}
   [junit4]   2> 1055023 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(AutoscalingHistoryHandlerTest_collection//collections/AutoscalingHistoryHandlerTest_collection/state.json/1)={
   [junit4]   2>   "pullReplicas":"0",
   [junit4]   2>   "replicationFactor":"3",
   [junit4]   2>   "router":{"name":"compositeId"},
   [junit4]   2>   "maxShardsPerNode":"3",
   [junit4]   2>   "autoAddReplicas":"false",
   [junit4]   2>   "nrtReplicas":"3",
   [junit4]   2>   "tlogReplicas":"0",
   [junit4]   2>   "shards":{"shard1":{
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "replicas":{
   [junit4]   2>         "core_node3":{
   [junit4]   2>           "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
   [junit4]   2>           "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "node_name":null,
   [junit4]   2>           "type":"NRT"},
   [junit4]   2>         "core_node5":{
   [junit4]   2>           "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
   [junit4]   2>           "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "node_name":null,
   [junit4]   2>           "type":"NRT"},
   [junit4]   2>         "core_node6":{
   [junit4]   2>           "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
   [junit4]   2>           "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>           "node_name":"127.0.0.1:40647_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT"}}}}}
   [junit4]   2> 1055023 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
   [junit4]   2>   "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
   [junit4]   2>   "core_node_name":"core_node5",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>   "node_name":"127.0.0.1:40647_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"AutoscalingHistoryHandlerTest_collection",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 1055023 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
   [junit4]   2>   "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
   [junit4]   2>   "core_node_name":"core_node5",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>   "node_name":"127.0.0.1:40647_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"AutoscalingHistoryHandlerTest_collection",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 1055023 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node5:{"core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2","base_url":"http://127.0.0.1:40647/solr","node_name":"127.0.0.1:40647_solr","state":"down","type":"NRT"}
   [junit4]   2> 1055023 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(AutoscalingHistoryHandlerTest_collection//collections/AutoscalingHistoryHandlerTest_collection/state.json/1)={
   [junit4]   2>   "pullReplicas":"0",
   [junit4]   2>   "replicationFactor":"3",
   [junit4]   2>   "router":{"name":"compositeId"},
   [junit4]   2>   "maxShardsPerNode":"3",
   [junit4]   2>   "autoAddReplicas":"false",
   [junit4]   2>   "nrtReplicas":"3",
   [junit4]   2>   "tlogReplicas":"0",
   [junit4]   2>   "shards":{"shard1":{
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "replicas":{
   [junit4]   2>         "core_node3":{
   [junit4]   2>           "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
   [junit4]   2>           "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "node_name":null,
   [junit4]   2>           "type":"NRT"},
   [junit4]   2>         "core_node5":{
   [junit4]   2>           "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
   [junit4]   2>           "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>           "node_name":"127.0.0.1:40647_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT"},
   [junit4]   2>         "core_node6":{
   [junit4]   2>           "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
   [junit4]   2>           "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>           "node_name":"127.0.0.1:40647_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT"}}}}}
   [junit4]   2> 1055024 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.Overseer processMessage: queueSize: 3, message = {
   [junit4]   2>   "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
   [junit4]   2>   "core_node_name":"core_node3",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>   "node_name":"127.0.0.1:40647_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"AutoscalingHistoryHandlerTest_collection",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 1055024 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
   [junit4]   2>   "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
   [junit4]   2>   "core_node_name":"core_node3",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>   "node_name":"127.0.0.1:40647_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"AutoscalingHistoryHandlerTest_collection",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 1055024 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node3:{"core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1","base_url":"http://127.0.0.1:40647/solr","node_name":"127.0.0.1:40647_solr","state":"down","type":"NRT"}
   [junit4]   2> 1055024 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(AutoscalingHistoryHandlerTest_collection//collections/AutoscalingHistoryHandlerTest_collection/state.json/1)={
   [junit4]   2>   "pullReplicas":"0",
   [junit4]   2>   "replicationFactor":"3",
   [junit4]   2>   "router":{"name":"compositeId"},
   [junit4]   2>   "maxShardsPerNode":"3",
   [junit4]   2>   "autoAddReplicas":"false",
   [junit4]   2>   "nrtReplicas":"3",
   [junit4]   2>   "tlogReplicas":"0",
   [junit4]   2>   "shards":{"shard1":{
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "replicas":{
   [junit4]   2>         "core_node3":{
   [junit4]   2>           "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
   [junit4]   2>           "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>           "node_name":"127.0.0.1:40647_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT"},
   [junit4]   2>         "core_node5":{
   [junit4]   2>           "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
   [junit4]   2>           "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>           "node_name":"127.0.0.1:40647_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT"},
   [junit4]   2>         "core_node6":{
   [junit4]   2>           "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
   [junit4]   2>           "base_url":"http://127.0.0.1:40647/solr",
   [junit4]   2>           "node_name":"127.0.0.1:40647_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT"}}}}}
   [junit4]   2> 1055125 DEBUG (OverseerStateUpdate-72441443923787782-127.0.0.1:40647_solr-n_0000000000) [    ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/AutoscalingHistoryHandlerTest_collection/state.json version: 1
   [junit4]   2> 1055126 INFO  (zkCallback-682-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/AutoscalingHistoryHandlerTest_collection/state.json] for collection [AutoscalingHistoryHandlerTest_collection] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 1055126 INFO  (zkCallback-682-thread-2) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/AutoscalingHistoryHandlerTest_collection/state.json] for collection [AutoscalingHistoryHandlerTest_collection] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 1055806 DEBUG (ScheduledTrigger-1082-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1056143 INFO  (qtp695522602-4178) [n:127.0.0.1:40647_solr c:AutoscalingHistoryHandlerTest_collection s:shard1 r:core_node5 x:AutoscalingHistoryHandlerTest_collection_shard1_replica_n2

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

ooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
   [junit4]   2> 4247203 INFO  (SUITE-IndexSizeTriggerTest-seed#[EE2C68D3A3C4BEC6]-worker) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:43746 43746
   [junit4]   2> 4247308 INFO  (Thread-6264) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:43746 43746
   [junit4]   2> 4247312 WARN  (Thread-6264) [    ] o.a.s.c.ZkTestServer Watch limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2> 	5	/solr/aliases.json
   [junit4]   2> 	5	/solr/clusterprops.json
   [junit4]   2> 	2	/solr/security.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2> 	5	/solr/clusterstate.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2> 	5	/solr/live_nodes
   [junit4]   2> 	5	/solr/collections
   [junit4]   2> 
   [junit4]   2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_EE2C68D3A3C4BEC6-001
   [junit4]   2> Apr 12, 2018 8:48:02 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=1345, maxMBSortInHeap=7.963945488442609, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@1f915d9f), locale=lt, timezone=Europe/Busingen
   [junit4]   2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation 1.8.0_152 (64-bit)/cpus=4,threads=1,free=92190208,total=515375104
   [junit4]   2> NOTE: All tests run in this JVM: [DistributedFacetPivotSmallAdvancedTest, MergeStrategyTest, DistributedMLTComponentTest, TestUseDocValuesAsStored2, TestMinMaxOnMultiValuedField, TestSerializedLuceneMatchVersion, TestSolrJ, TestUninvertingReader, TriggerIntegrationTest, BigEndianAscendingWordSerializerTest, XsltUpdateRequestHandlerTest, TestManagedSynonymFilterFactory, ChaosMonkeySafeLeaderTest, TestSearchPerf, JavabinLoaderTest, ZkFailoverTest, TestBinaryResponseWriter, SolrInfoBeanTest, TestReversedWildcardFilterFactory, TestJsonRequest, TermsComponentTest, DocExpirationUpdateProcessorFactoryTest, ClassificationUpdateProcessorIntegrationTest, TestFilteredDocIdSet, TestLRUCache, TestJsonFacetRefinement, DistributedIntervalFacetingTest, TestNumericRangeQuery32, TestInitQParser, TestFieldCacheSortRandom, TestSimpleTrackingShardHandler, TestMissingGroups, SignatureUpdateProcessorFactoryTest, TestManagedSchemaThreadSafety, CheckHdfsIndexTest, NodeLostTriggerIntegrationTest, TestMacros, AutoscalingHistoryHandlerTest, TestCollectionAPIs, TestQueryWrapperFilter, TestStreamBody, TestNestedDocsSort, TestDistributedGrouping, TlogReplayBufferedWhileIndexingTest, TestBulkSchemaAPI, TestConfigOverlay, TestFieldTypeCollectionResource, BJQParserTest, SortByFunctionTest, NodeMutatorTest, DOMUtilTest, TestHttpShardHandlerFactory, TestSurroundQueryParser, QueryParsingTest, PathHierarchyTokenizerFactoryTest, SharedFSAutoReplicaFailoverTest, TestStressRecovery, QueryEqualityTest, FieldMutatingUpdateProcessorTest, SearchHandlerTest, TestDownShardTolerantSearch, TestImpersonationWithHadoopAuth, PKIAuthenticationIntegrationTest, TestEmbeddedSolrServerSchemaAPI, HdfsWriteToMultipleCollectionsTest, OverseerTest, PrimitiveFieldTypeTest, AtomicUpdateProcessorFactoryTest, HdfsChaosMonkeySafeLeaderTest, DistributedQueryComponentCustomSortTest, TestLegacyFieldCache, TestSolrIndexConfig, TestFunctionQuery, TestRandomRequestDistribution, TestLuceneIndexBackCompat, FileUtilsTest, TestStandardQParsers, TestLeaderElectionZkExpiry, TestRuleBasedAuthorizationPlugin, MetricTriggerTest, TestManagedResource, TestLRUStatsCache, DistributedQueueTest, HttpSolrCallGetCoreTest, SliceStateTest, TestFoldingMultitermQuery, TestLegacyNumericUtils, TestSweetSpotSimilarityFactory, TestPartialUpdateDeduplication, DistribCursorPagingTest, CollectionsAPISolrJTest, AlternateDirectoryTest, TestGeoJSONResponseWriter, SolrCoreMetricManagerTest, ReplaceNodeTest, HdfsBasicDistributedZk2Test, TestReplicationHandler, CoreAdminRequestStatusTest, HdfsCollectionsAPIDistributedZkTest, AutoAddReplicasIntegrationTest, TestZkChroot, TestTrie, MoveReplicaTest, HdfsThreadLeakTest, TestSlowCompositeReaderWrapper, RequiredFieldsTest, TestSubQueryTransformer, TestMiniSolrCloudClusterSSL, FacetPivotSmallTest, TestDeleteCollectionOnDownNodes, TestXIncludeConfig, TestFastLRUCache, TestSchemaResource, TestConfigSetsAPIExclusivity, RollingRestartTest, TestDistribIDF, TestFieldCache, RestoreTriggerStateTest, DocumentBuilderTest, TestDirectoryFactory, TestComputePlanAction, SuggesterTest, ZkControllerTest, TestInfoStreamLogging, TestSizeLimitedDistributedMap, TestCloudSearcherWarming, DeleteReplicaTest, TestCloudPivotFacet, PrimUtilsTest, PreAnalyzedUpdateProcessorTest, UnloadDistributedZkTest, LeaderElectionIntegrationTest, LeaderElectionTest, ZkSolrClientTest, ZkCLITest, TestDistributedSearch, SolrCoreTest, ConvertedLegacyTest, BasicFunctionalityTest, TestLazyCores, SuggesterFSTTest, TestStressLucene, SpatialFilterTest, PolyFieldTest, NoCacheHeaderTest, SchemaVersionSpecificBehaviorTest, TestAtomicUpdateErrorCases, DefaultValueUpdateProcessorTest, DebugComponentTest, DisMaxRequestHandlerTest, TestQueryUtils, FileBasedSpellCheckerTest, TestValueSourceCache, MoreLikeThisHandlerTest, FastVectorHighlighterTest, LoggingHandlerTest, ReturnFieldsTest, TestCSVResponseWriter, TestAnalyzedSuggestions, UniqFieldsUpdateProcessorFactoryTest, JsonLoaderTest, TestPHPSerializedResponseWriter, CSVRequestHandlerTest, TestComponentsName, SearchHandlerTest, SOLR749Test, TestQuerySenderNoQuery, SolrIndexConfigTest, BadComponentTest, TestMergePolicyConfig, TestSolrDeletionPolicy2, MultiTermTest, TestDocSet, TestElisionMultitermQuery, OutputWriterTest, TestPostingsSolrHighlighter, SpellPossibilityIteratorTest, TestCodecSupport, TestBM25SimilarityFactory, TestFastOutputStream, OpenExchangeRatesOrgProviderTest, ChaosMonkeyNothingIsSafeTest, ChaosMonkeySafeLeaderWithPullReplicasTest, CloudExitableDirectoryReaderTest, CollectionPropsTest, ConcurrentCreateRoutedAliasTest, DeleteLastCustomShardedReplicaTest, DeleteShardTest, DistribDocExpirationUpdateProcessorTest, MoveReplicaHDFSTest, TestCloudPseudoReturnFields, TestConfigSetsAPIZkFailure, TestCryptoKeys, TestLockTree, TestOnReconnectListenerSupport, TestRandomFlRTGCloud, TestSSLRandomization, TestSolrCloudWithSecureImpersonation, TestStressCloudBlindAtomicUpdates, TestTlogReplica, AssignTest, CollectionsAPIDistributedZkTest, TestRequestStatusCollectionAPI, IndexSizeTriggerTest]
   [junit4] Completed [612/802 (2!)] on J1 in 8.92s, 4 tests, 2 failures, 1 error <<< FAILURES!

[...truncated 46678 lines...]
-ecj-javadoc-lint-tests:
    [mkdir] Created dir: /tmp/ecj808234449
 [ecj-lint] Compiling 895 source files to /tmp/ecj808234449
 [ecj-lint] invalid Class-Path header in manifest of jar file: /home/jenkins/.ivy2/cache/org.restlet.jee/org.restlet/jars/org.restlet-2.3.0.jar
 [ecj-lint] invalid Class-Path header in manifest of jar file: /home/jenkins/.ivy2/cache/org.restlet.jee/org.restlet.ext.servlet/jars/org.restlet.ext.servlet-2.3.0.jar
 [ecj-lint] ----------
 [ecj-lint] 1. WARNING in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test/org/apache/solr/analysis/TokenizerChainTest.java (at line 37)
 [ecj-lint] 	TokenizerChain tokenizerChain = new TokenizerChain(
 [ecj-lint] 	               ^^^^^^^^^^^^^^
 [ecj-lint] Resource leak: 'tokenizerChain' is never closed
 [ecj-lint] ----------
 [ecj-lint] ----------
 [ecj-lint] 2. ERROR in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test/org/apache/solr/cloud/LeaderVoteWaitTimeoutTest.java (at line 28)
 [ecj-lint] 	import java.util.Set;
 [ecj-lint] 	       ^^^^^^^^^^^^^
 [ecj-lint] The import java.util.Set is never used
 [ecj-lint] ----------
 [ecj-lint] 3. ERROR in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test/org/apache/solr/cloud/LeaderVoteWaitTimeoutTest.java (at line 37)
 [ecj-lint] 	import org.apache.solr.common.cloud.CollectionStatePredicate;
 [ecj-lint] 	       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
 [ecj-lint] The import org.apache.solr.common.cloud.CollectionStatePredicate is never used
 [ecj-lint] ----------
 [ecj-lint] 4. ERROR in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test/org/apache/solr/cloud/LeaderVoteWaitTimeoutTest.java (at line 38)
 [ecj-lint] 	import org.apache.solr.common.cloud.DocCollection;
 [ecj-lint] 	       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
 [ecj-lint] The import org.apache.solr.common.cloud.DocCollection is never used
 [ecj-lint] ----------
 [ecj-lint] 4 problems (3 errors, 1 warning)

BUILD FAILED
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/build.xml:633: The following error occurred while executing this line:
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/build.xml:101: The following error occurred while executing this line:
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build.xml:690: The following error occurred while executing this line:
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/common-build.xml:2095: The following error occurred while executing this line:
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/common-build.xml:2128: Compile failed; see the compiler error output for details.

Total time: 214 minutes 26 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any

[JENKINS] Lucene-Solr-Tests-master - Build # 2486 - Unstable

Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/2486/

3 tests failed.
FAILED:  org.apache.solr.cloud.autoscaling.NodeAddedTriggerTest.testRestoreState

Error Message:
Did not expect the processor to fire on first run! event={   "id":"156cc960110160T20cxdayp2qu21a0p7q1kzpkgm",   "source":"node_added_trigger",   "eventTime":6030586666877280,   "eventType":"NODEADDED",   "properties":{     "eventTimes":[       6030586666877280,       6030586666897978],     "nodeNames":[       "127.0.0.1:38015_solr",       "127.0.0.1:38653_solr"]}}

Stack Trace:
java.lang.AssertionError: Did not expect the processor to fire on first run! event={
  "id":"156cc960110160T20cxdayp2qu21a0p7q1kzpkgm",
  "source":"node_added_trigger",
  "eventTime":6030586666877280,
  "eventType":"NODEADDED",
  "properties":{
    "eventTimes":[
      6030586666877280,
      6030586666897978],
    "nodeNames":[
      "127.0.0.1:38015_solr",
      "127.0.0.1:38653_solr"]}}
	at __randomizedtesting.SeedInfo.seed([C3FA17078818EB11:D54B39470219307]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.autoscaling.NodeAddedTriggerTest.lambda$new$0(NodeAddedTriggerTest.java:49)
	at org.apache.solr.cloud.autoscaling.NodeAddedTrigger.run(NodeAddedTrigger.java:161)
	at org.apache.solr.cloud.autoscaling.NodeAddedTriggerTest.testRestoreState(NodeAddedTriggerTest.java:257)
	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:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	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:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	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.search.TestSolr4Spatial2.testLatLonRetrieval

Error Message:
mismatch: '-40,40'!='-40,39.99999997' @ response/docs/[4]/llp_N_dv_dvasst/[1]

Stack Trace:
java.lang.RuntimeException: mismatch: '-40,40'!='-40,39.99999997' @ response/docs/[4]/llp_N_dv_dvasst/[1]
	at __randomizedtesting.SeedInfo.seed([C3FA17078818EB11:E50E7DFB84BFAD5F]:0)
	at org.apache.solr.SolrTestCaseJ4.assertJQ(SolrTestCaseJ4.java:1004)
	at org.apache.solr.SolrTestCaseJ4.assertJQ(SolrTestCaseJ4.java:951)
	at org.apache.solr.search.TestSolr4Spatial2.testLatLonRetrieval(TestSolr4Spatial2.java:226)
	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:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	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:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	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.client.solrj.impl.CloudSolrClientTest.testRetryUpdatesWhenClusterStateIsStale

Error Message:
Could not load collection from ZK: stale_state_test_col

Stack Trace:
org.apache.solr.common.SolrException: Could not load collection from ZK: stale_state_test_col
	at __randomizedtesting.SeedInfo.seed([F3F930E057A345A3:47C8A808B44A338F]:0)
	at org.apache.solr.common.cloud.ZkStateReader.getCollectionLive(ZkStateReader.java:1250)
	at org.apache.solr.common.cloud.ZkStateReader$LazyCollectionRef.get(ZkStateReader.java:679)
	at org.apache.solr.common.cloud.ClusterState.getCollectionOrNull(ClusterState.java:148)
	at org.apache.solr.common.cloud.ClusterState.getCollectionOrNull(ClusterState.java:131)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:154)
	at org.apache.solr.client.solrj.impl.CloudSolrClientTest.testRetryUpdatesWhenClusterStateIsStale(CloudSolrClientTest.java:789)
	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:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at org.junit.rules.ExpectedException$ExpectedExceptionStatement.evaluate(ExpectedException.java:110)
	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:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	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)
Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/stale_state_test_col/state.json
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:130)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:54)
	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1215)
	at org.apache.solr.common.cloud.SolrZkClient.lambda$getData$5(SolrZkClient.java:340)
	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:340)
	at org.apache.solr.common.cloud.ZkStateReader.fetchCollectionState(ZkStateReader.java:1262)
	at org.apache.solr.common.cloud.ZkStateReader.getCollectionLive(ZkStateReader.java:1248)
	... 45 more




Build Log:
[...truncated 13236 lines...]
   [junit4] Suite: org.apache.solr.search.TestSolr4Spatial2
   [junit4]   2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.search.TestSolr4Spatial2_C3FA17078818EB11-001/init-core-data-001
   [junit4]   2> 1889222 WARN  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4
   [junit4]   2> 1889235 INFO  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 1889236 INFO  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 1889236 INFO  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 1889236 INFO  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 1889237 INFO  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 1889442 INFO  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 1889480 INFO  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.s.IndexSchema [null] Schema name=test
   [junit4]   2> 1889555 WARN  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.SpatialTermQueryPrefixTreeFieldType]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 1889590 WARN  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.SpatialPointVectorFieldType]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 1889954 INFO  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.s.IndexSchema Loaded schema test/1.4 with uniqueid field id
   [junit4]   2> 1890248 INFO  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2b3ab971
   [junit4]   2> 1890285 INFO  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2b3ab971
   [junit4]   2> 1890286 INFO  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2b3ab971
   [junit4]   2> 1890319 INFO  (coreLoadExecutor-3184-thread-1) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 1890320 INFO  (coreLoadExecutor-3184-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-master/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 1890540 INFO  (coreLoadExecutor-3184-thread-1) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 1890612 INFO  (coreLoadExecutor-3184-thread-1) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 1890663 INFO  (coreLoadExecutor-3184-thread-1) [    x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.4 with uniqueid field id
   [junit4]   2> 1890663 INFO  (coreLoadExecutor-3184-thread-1) [    x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1, trusted=true
   [junit4]   2> 1890664 INFO  (coreLoadExecutor-3184-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@2b3ab971
   [junit4]   2> 1890664 INFO  (coreLoadExecutor-3184-thread-1) [    x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 1890664 INFO  (coreLoadExecutor-3184-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.search.TestSolr4Spatial2_C3FA17078818EB11-001/init-core-data-001/]
   [junit4]   2> 1890666 INFO  (coreLoadExecutor-3184-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=19, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 1891021 INFO  (coreLoadExecutor-3184-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1891021 INFO  (coreLoadExecutor-3184-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1891022 INFO  (coreLoadExecutor-3184-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=28.9951171875, floorSegmentMB=0.4697265625, forceMergeDeletesPctAllowed=26.197763855225283, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1891022 INFO  (coreLoadExecutor-3184-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@493bb521[collection1] main]
   [junit4]   2> 1891022 WARN  (coreLoadExecutor-3184-thread-1) [    x:collection1] o.a.s.r.ManagedResourceStorage Cannot write to config directory /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1/conf; switching to use InMemory storage instead.
   [junit4]   2> 1891023 INFO  (coreLoadExecutor-3184-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 1891024 INFO  (SUITE-TestSolr4Spatial2-seed#[C3FA17078818EB11]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 1891078 INFO  (searcherExecutor-3185-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@493bb521[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1891079 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testRptWithGeometryGeo3dField
   [junit4]   2> 1891080 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1891080 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1891289 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.s.AbstractSpatialPrefixTreeFieldType srptgeom_geo3d{class=org.apache.solr.schema.SpatialRecursivePrefixTreeFieldType,analyzer=org.apache.solr.schema.FieldType$DefaultAnalyzer,args=null} strat: RecursivePrefixTreeStrategy(SPG:(GeohashPrefixTree(maxLevels:11,ctx:SpatialContext{geo=true, calculator=org.apache.lucene.spatial.spatial4j.Geo3dDistanceCalculator@3eadcd22, worldBounds=Rect(minX=-180.0,maxX=180.0,minY=-90.0,maxY=90.0)})),pruneLeafyBranches) maxLevels: 11
   [junit4]   2> 1891806 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 725
   [junit4]   2> 1892196 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[1]} 0 369
   [junit4]   2> 1892196 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=true,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1892196 WARN  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 Starting optimize... Reading and rewriting the entire index! Use with care.
   [junit4]   2> 1892429 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1892467 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3b017a3[collection1] main]
   [junit4]   2> 1892467 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1892469 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3b017a3[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(8.0.0):C2)))}
   [junit4]   2> 1892469 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{optimize=} 0 272
   [junit4]   2> 1892502 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1892502 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1892503 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1892503 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 0
   [junit4]   2> 1892761 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q={!cache%3Dfalse+field+f%3Dsrptgeom_geo3d}Intersects(ENVELOPE(-20,+-10.0001,+30,+15.0001))&sort=id+asc&wt=xml} hits=1 status=0 QTime=257
   [junit4]   2> 1892795 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q={!cache%3Dfalse+field+f%3Dsrptgeom_geo3d}Intersects(ENVELOPE(-20,+-10.0001,+30,+15.0001))&sort=id+asc&wt=xml} hits=1 status=0 QTime=291
   [junit4]   2> 1892795 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[3]} 0 0
   [junit4]   2> 1892796 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1892796 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1892797 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6a446fe6[collection1] main]
   [junit4]   2> 1892832 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6a446fe6[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(8.0.0):C2) Uninverting(_2(8.0.0):c1)))}
   [junit4]   2> 1892832 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1892832 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 36
   [junit4]   2> 1892834 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q={!cache%3Dfalse+field+f%3Dsrptgeom_geo3d}Intersects(ENVELOPE(-20,+-10.0001,+30,+15.0001))&sort=id+asc&wt=xml} hits=1 status=0 QTime=331
   [junit4]   2> 1892978 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&facet.heatmap=srptgeom_geo3d&json.nl=map&facet=true&wt=xml} hits=3 status=0 QTime=111
   [junit4]   2> 1893307 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q={!cache%3Dfalse+field+f%3Dsrptgeom_geo3d}Intersects(POLYGON((-11+12,+10.5+12,+-11+11,+-11+12)))&sort=id+asc&wt=xml} hits=2 status=0 QTime=327
   [junit4]   2> 1893308 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryGeo3dField-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testRptWithGeometryGeo3dField
   [junit4]   2> 1893336 INFO  (TEST-TestSolr4Spatial2.testBadScoreParam-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testBadScoreParam
   [junit4]   2> 1893337 INFO  (TEST-TestSolr4Spatial2.testBadScoreParam-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1893337 INFO  (TEST-TestSolr4Spatial2.testBadScoreParam-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1893381 INFO  (TEST-TestSolr4Spatial2.testBadScoreParam-seed#[C3FA17078818EB11]) [    ] o.a.s.h.RequestHandlerBase Ignoring exception matching .
   [junit4]   2> 1893381 INFO  (TEST-TestSolr4Spatial2.testBadScoreParam-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q={!field+f%3Dbbox+filter%3Dfalse+score%3Dbogus}Intersects(ENVELOPE(0,0,12,12))&qt=&start=0&rows=20&version=2.2} status=400 QTime=44
   [junit4]   2> 1893382 INFO  (TEST-TestSolr4Spatial2.testBadScoreParam-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testBadScoreParam
   [junit4]   2> 1893400 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testRptWithGeometryField
   [junit4]   2> 1893400 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1893400 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1893402 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.s.AbstractSpatialPrefixTreeFieldType srptgeom{class=org.apache.solr.schema.SpatialRecursivePrefixTreeFieldType,analyzer=org.apache.solr.schema.FieldType$DefaultAnalyzer,args=null} strat: RecursivePrefixTreeStrategy(SPG:(GeohashPrefixTree(maxLevels:11,ctx:SpatialContext{geo=true, calculator=Haversine, worldBounds=Rect(minX=-180.0,maxX=180.0,minY=-90.0,maxY=90.0)})),pruneLeafyBranches) maxLevels: 11
   [junit4]   2> 1893449 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 48
   [junit4]   2> 1893671 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[1]} 0 221
   [junit4]   2> 1893671 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=true,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1893671 WARN  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 Starting optimize... Reading and rewriting the entire index! Use with care.
   [junit4]   2> 1894247 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1894248 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@27d8f209[collection1] main]
   [junit4]   2> 1894248 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1894252 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@27d8f209[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_4(8.0.0):C2)))}
   [junit4]   2> 1894252 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{optimize=} 0 580
   [junit4]   2> 1894252 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1894252 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1894253 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1894253 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 0
   [junit4]   2> 1894254 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q={!cache%3Dfalse+field+f%3Dsrptgeom}Intersects(ENVELOPE(-20,+-10.0001,+30,+15.0001))&sort=id+asc&wt=xml} hits=1 status=0 QTime=1
   [junit4]   2> 1894434 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q={!cache%3Dfalse+field+f%3Dsrptgeom}Intersects(ENVELOPE(-20,+-10.0001,+30,+15.0001))&sort=id+asc&wt=xml} hits=1 status=0 QTime=181
   [junit4]   2> 1894507 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[3]} 0 72
   [junit4]   2> 1894507 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1894507 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1894509 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3499b62[collection1] main]
   [junit4]   2> 1894510 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3499b62[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_4(8.0.0):C2) Uninverting(_5(8.0.0):c1)))}
   [junit4]   2> 1894527 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1894551 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 44
   [junit4]   2> 1894552 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q={!cache%3Dfalse+field+f%3Dsrptgeom}Intersects(ENVELOPE(-20,+-10.0001,+30,+15.0001))&sort=id+asc&wt=xml} hits=1 status=0 QTime=299
   [junit4]   2> 1894553 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&facet.heatmap=srptgeom&json.nl=map&facet=true&wt=xml} hits=3 status=0 QTime=0
   [junit4]   2> 1894554 INFO  (TEST-TestSolr4Spatial2.testRptWithGeometryField-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testRptWithGeometryField
   [junit4]   2> 1894917 INFO  (TEST-TestSolr4Spatial2.testConstantScoreQueryWithFilterPartOnly-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testConstantScoreQueryWithFilterPartOnly
   [junit4]   2> 1894917 INFO  (TEST-TestSolr4Spatial2.testConstantScoreQueryWithFilterPartOnly-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1894917 INFO  (TEST-TestSolr4Spatial2.testConstantScoreQueryWithFilterPartOnly-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1894920 INFO  (TEST-TestSolr4Spatial2.testConstantScoreQueryWithFilterPartOnly-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[1]} 0 2
   [junit4]   2> 1894920 INFO  (TEST-TestSolr4Spatial2.testConstantScoreQueryWithFilterPartOnly-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1894920 INFO  (TEST-TestSolr4Spatial2.testConstantScoreQueryWithFilterPartOnly-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1894991 INFO  (TEST-TestSolr4Spatial2.testConstantScoreQueryWithFilterPartOnly-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5f6e8c88[collection1] main]
   [junit4]   2> 1894991 INFO  (TEST-TestSolr4Spatial2.testConstantScoreQueryWithFilterPartOnly-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1894992 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5f6e8c88[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(8.0.0):c1)))}
   [junit4]   2> 1894992 INFO  (TEST-TestSolr4Spatial2.testConstantScoreQueryWithFilterPartOnly-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 72
   [junit4]   2> 1895029 INFO  (TEST-TestSolr4Spatial2.testConstantScoreQueryWithFilterPartOnly-seed#[C3FA17078818EB11]) [    ] o.a.s.s.AbstractSpatialPrefixTreeFieldType srptgeom{class=org.apache.solr.schema.SpatialRecursivePrefixTreeFieldType,analyzer=org.apache.solr.schema.FieldType$DefaultAnalyzer,args=null} strat: RecursivePrefixTreeStrategy(SPG:(GeohashPrefixTree(maxLevels:11,ctx:SpatialContext{geo=true, calculator=Haversine, worldBounds=Rect(minX=-180.0,maxX=180.0,minY=-90.0,maxY=90.0)})),pruneLeafyBranches) maxLevels: 11
   [junit4]   2> 1895030 INFO  (TEST-TestSolr4Spatial2.testConstantScoreQueryWithFilterPartOnly-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q={!geofilt+sfield%3D"srptgeom"+pt%3D"56.9484,24.0981"+d%3D100}&hl=true&hl.fl=srptgeom} hits=1 status=0 QTime=36
   [junit4]   2> 1895063 INFO  (TEST-TestSolr4Spatial2.testConstantScoreQueryWithFilterPartOnly-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testConstantScoreQueryWithFilterPartOnly
   [junit4]   2> 1895190 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLatLonRetrieval
   [junit4]   2> 1895190 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1895190 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1895302 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[4]} 0 110
   [junit4]   2> 1895321 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[3]} 0 0
   [junit4]   2> 1895321 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5]} 0 0
   [junit4]   2> 1895321 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[7]} 0 0
   [junit4]   2> 1895322 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8]} 0 0
   [junit4]   2> 1895336 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[1]} 0 0
   [junit4]   2> 1895371 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[6]} 0 12
   [junit4]   2> 1895371 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[2]} 0 0
   [junit4]   2> 1895372 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1895372 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1895372 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1895410 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@68b378c4[collection1] main]
   [junit4]   2> 1895410 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1895412 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@68b378c4[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_7(8.0.0):c9)))}
   [junit4]   2> 1895428 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 55
   [junit4]   2> 1895444 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&fl=*&sort=id+asc&wt=xml} hits=9 status=0 QTime=0
   [junit4]   2> 1895446 ERROR (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 query failed JSON validation. error=mismatch: '-40,40'!='-40,39.99999997' @ response/docs/[4]/llp_N_dv_dvasst/[1]
   [junit4]   2>  expected =response/docs/[4]/llp_N_dv_dvasst==['-45,45', '-40,40']
   [junit4]   2>  response = {
   [junit4]   2>   "responseHeader":{
   [junit4]   2>     "status":0,
   [junit4]   2>     "QTime":0},
   [junit4]   2>   "response":{"numFound":9,"start":0,"docs":[
   [junit4]   2>       {
   [junit4]   2>         "id":"0",
   [junit4]   2>         "llp_1_dv_st":"40.2996543270,-74.0824956673"},
   [junit4]   2>       {
   [junit4]   2>         "id":"1",
   [junit4]   2>         "llp_N_dv_st":["-40,40",
   [junit4]   2>           "-45,45"]},
   [junit4]   2>       {
   [junit4]   2>         "id":"2",
   [junit4]   2>         "llp_N_dv_st":["-40,40"]},
   [junit4]   2>       {
   [junit4]   2>         "id":"3",
   [junit4]   2>         "llp_1_dv_dvasst":"40.29965431,-74.08249572"},
   [junit4]   2>       {
   [junit4]   2>         "id":"4",
   [junit4]   2>         "llp_N_dv_dvasst":["-45,45",
   [junit4]   2>           "-40,39.99999997"]},
   [junit4]   2>       {
   [junit4]   2>         "id":"5",
   [junit4]   2>         "llp_N_dv_dvasst":["-40,39.99999997"]},
   [junit4]   2>       {
   [junit4]   2>         "id":"6",
   [junit4]   2>         "llp_N_dv_dvasst":["-90,179.99999992",
   [junit4]   2>           "-90,-180",
   [junit4]   2>           "0,0",
   [junit4]   2>           "0,179.99999992",
   [junit4]   2>           "0,-180",
   [junit4]   2>           "89.99999996,0",
   [junit4]   2>           "89.99999996,179.99999992",
   [junit4]   2>           "89.99999996,-180"]},
   [junit4]   2>       {
   [junit4]   2>         "id":"7"},
   [junit4]   2>       {
   [junit4]   2>         "id":"8"}]
   [junit4]   2>   }}
   [junit4]   2> 
   [junit4]   2>  request = q=*:*&fl=*&sort=id+asc&wt=xml
   [junit4]   2> 1895447 INFO  (TEST-TestSolr4Spatial2.testLatLonRetrieval-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLatLonRetrieval
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestSolr4Spatial2 -Dtests.method=testLatLonRetrieval -Dtests.seed=C3FA17078818EB11 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=ar-LB -Dtests.timezone=Indian/Comoro -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] ERROR   0.50s J1 | TestSolr4Spatial2.testLatLonRetrieval <<<
   [junit4]    > Throwable #1: java.lang.RuntimeException: mismatch: '-40,40'!='-40,39.99999997' @ response/docs/[4]/llp_N_dv_dvasst/[1]
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([C3FA17078818EB11:E50E7DFB84BFAD5F]:0)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertJQ(SolrTestCaseJ4.java:1004)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertJQ(SolrTestCaseJ4.java:951)
   [junit4]    > 	at org.apache.solr.search.TestSolr4Spatial2.testLatLonRetrieval(TestSolr4Spatial2.java:226)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 1895592 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:8006CD4E904505A9]}
   [junit4]   2> 1895592 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1895592 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1895736 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 35
   [junit4]   2> 1895736 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1895736 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1895738 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@21d7febe[collection1] main]
   [junit4]   2> 1895739 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1895741 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@21d7febe[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_8(8.0.0):c1)))}
   [junit4]   2> 1895756 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 19
   [junit4]   2> 1895793 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1895794 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1895794 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1895794 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1895796 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1e46ac89[collection1] main]
   [junit4]   2> 1895830 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1895831 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1e46ac89[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_9(8.0.0):c1)))}
   [junit4]   2> 1895845 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 50
   [junit4]   2> 1895846 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1895847 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:8006CD4E904505A9]}
   [junit4]   2> 1896102 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:345071B2A487CE85]}
   [junit4]   2> 1896102 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1896102 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1896103 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1896103 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1896103 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1896194 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1c638ac8[collection1] main]
   [junit4]   2> 1896195 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1896196 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1c638ac8[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(8.0.0):c1)))}
   [junit4]   2> 1896210 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 107
   [junit4]   2> 1896211 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1896212 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1896212 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1896212 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1896214 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4cb0f953[collection1] main]
   [junit4]   2> 1896247 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1896252 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4cb0f953[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_b(8.0.0):c1)))}
   [junit4]   2> 1896267 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 55
   [junit4]   2> 1896267 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1896324 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:345071B2A487CE85]}
   [junit4]   2> 1896379 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:BAB9E76EF543864E]}
   [junit4]   2> 1896379 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1896379 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1896380 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1896380 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1896380 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1896415 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@283df7b3[collection1] main]
   [junit4]   2> 1896435 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1896436 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@283df7b3[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_c(8.0.0):c1)))}
   [junit4]   2> 1896449 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 69
   [junit4]   2> 1896450 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1896502 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 49
   [junit4]   2> 1896503 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1896503 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1896505 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@613a5300[collection1] main]
   [junit4]   2> 1896505 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1896507 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@613a5300[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_d(8.0.0):c1)))}
   [junit4]   2> 1896522 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 19
   [junit4]   2> 1896523 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1896539 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:BAB9E76EF543864E]}
   [junit4]   2> 1896649 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:8B574C8B99BDDD67]}
   [junit4]   2> 1896649 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1896649 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1896669 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 19
   [junit4]   2> 1896669 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1896669 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1896671 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@694fe9f2[collection1] main]
   [junit4]   2> 1896671 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1896677 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@694fe9f2[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_e(8.0.0):c1)))}
   [junit4]   2> 1896684 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 15
   [junit4]   2> 1896685 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1896685 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1896686 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1896686 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1896687 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@cdfd5b[collection1] main]
   [junit4]   2> 1896688 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1896694 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@cdfd5b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_f(8.0.0):c1)))}
   [junit4]   2> 1896721 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 35
   [junit4]   2> 1896722 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1896723 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:8B574C8B99BDDD67]}
   [junit4]   2> 1896779 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:C796C92638B51DDC]}
   [junit4]   2> 1896779 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1896779 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1896780 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1896780 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1896780 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1896797 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6a5afb54[collection1] main]
   [junit4]   2> 1896797 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1896803 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6a5afb54[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_g(8.0.0):c1)))}
   [junit4]   2> 1896814 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 33
   [junit4]   2> 1896815 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1896816 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1896816 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1896816 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1896818 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@363074d2[collection1] main]
   [junit4]   2> 1896818 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1896823 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@363074d2[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_h(8.0.0):c1)))}
   [junit4]   2> 1896831 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 15
   [junit4]   2> 1896832 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1896833 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:C796C92638B51DDC]}
   [junit4]   2> 1896925 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:566C1A79450950DC]}
   [junit4]   2> 1896925 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1896926 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1896927 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 1
   [junit4]   2> 1896927 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1896927 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1896967 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3589c9a8[collection1] main]
   [junit4]   2> 1896967 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1896970 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3589c9a8[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_i(8.0.0):c1)))}
   [junit4]   2> 1896981 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 53
   [junit4]   2> 1896981 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1896982 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1896982 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1896982 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1897001 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@470b6066[collection1] main]
   [junit4]   2> 1897001 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1897006 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@470b6066[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_j(8.0.0):c1)))}
   [junit4]   2> 1897018 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 35
   [junit4]   2> 1897019 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1897020 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:566C1A79450950DC]}
   [junit4]   2> 1897076 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:68B27EFF573940DA]}
   [junit4]   2> 1897076 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1897076 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1897077 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1897077 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1897077 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1897113 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4bdd29a2[collection1] main]
   [junit4]   2> 1897113 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1897116 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4bdd29a2[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_k(8.0.0):c1)))}
   [junit4]   2> 1897127 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 49
   [junit4]   2> 1897127 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1897128 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1897128 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1897129 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1897209 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@741af4ff[collection1] main]
   [junit4]   2> 1897209 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1897225 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@741af4ff[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_l(8.0.0):c1)))}
   [junit4]   2> 1897225 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 96
   [junit4]   2> 1897226 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1897227 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:68B27EFF573940DA]}
   [junit4]   2> 1897237 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:F401E485742DD474]}
   [junit4]   2> 1897237 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1897238 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1897238 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1897238 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1897238 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1897273 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@447cce56[collection1] main]
   [junit4]   2> 1897273 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1897277 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@447cce56[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_m(8.0.0):c1)))}
   [junit4]   2> 1897293 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 54
   [junit4]   2> 1897293 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1897294 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1897294 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1897294 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1897327 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1221e9ca[collection1] main]
   [junit4]   2> 1897327 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1897334 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1221e9ca[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_n(8.0.0):c1)))}
   [junit4]   2> 1897342 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 47
   [junit4]   2> 1897342 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1897343 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:F401E485742DD474]}
   [junit4]   2> 1897634 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:C6AD01EB03E6C32E]}
   [junit4]   2> 1897635 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1897635 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1897635 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1897636 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1897636 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1897670 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5e448e2[collection1] main]
   [junit4]   2> 1897671 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1897679 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5e448e2[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_o(8.0.0):c1)))}
   [junit4]   2> 1897686 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 50
   [junit4]   2> 1897686 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1897687 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1897687 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1897687 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@134df1b9 commitCommandVersion:0
   [junit4]   2> 1897689 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1ca4b320[collection1] main]
   [junit4]   2> 1897706 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1897707 INFO  (searcherExecutor-3185-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1ca4b320[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_p(8.0.0):c1)))}
   [junit4]   2> 1897722 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 35
   [junit4]   2> 1897723 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=/select params={q=id:0} hits=1 status=0 QTime=0
   [junit4]   2> 1897724 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:C6AD01EB03E6C32E]}
   [junit4]   2> 1897798 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLLPDecodeIsStableAndPrecise {seed=[C3FA17078818EB11:1126575167B1F47C]}
   [junit4]   2> 1897798 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1897798 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
   [junit4]   2> 1897799 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecise-seed#[C3FA17078818EB11]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[0]} 0 0
   [junit4]   2> 1897832 INFO  (TEST-TestSolr4Spatial2.testLLPDecodeIsStableAndPrecis

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

ngs.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

jar-checksums:
    [mkdir] Created dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/null1980063897
     [copy] Copying 40 files to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/null1980063897
   [delete] Deleting directory /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/null1980063897

resolve-example:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

resolve-server:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml

resolve:

jar-checksums:
    [mkdir] Created dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null913839156
     [copy] Copying 246 files to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null913839156
   [delete] Deleting directory /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null913839156

check-working-copy:
[ivy:cachepath] :: resolving dependencies :: org.eclipse.jgit#org.eclipse.jgit-caller;working
[ivy:cachepath] 	confs: [default]
[ivy:cachepath] 	found org.eclipse.jgit#org.eclipse.jgit;4.6.0.201612231935-r in public
[ivy:cachepath] 	found com.jcraft#jsch;0.1.53 in public
[ivy:cachepath] 	found com.googlecode.javaewah#JavaEWAH;1.1.6 in public
[ivy:cachepath] 	found org.apache.httpcomponents#httpclient;4.3.6 in public
[ivy:cachepath] 	found org.apache.httpcomponents#httpcore;4.3.3 in public
[ivy:cachepath] 	found commons-logging#commons-logging;1.1.3 in public
[ivy:cachepath] 	found commons-codec#commons-codec;1.6 in public
[ivy:cachepath] 	found org.slf4j#slf4j-api;1.7.2 in public
[ivy:cachepath] :: resolution report :: resolve 19ms :: artifacts dl 1ms
	---------------------------------------------------------------------
	|                  |            modules            ||   artifacts   |
	|       conf       | number| search|dwnlded|evicted|| number|dwnlded|
	---------------------------------------------------------------------
	|      default     |   8   |   0   |   0   |   0   ||   8   |   0   |
	---------------------------------------------------------------------
[wc-checker] Initializing working copy...
[wc-checker] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
[wc-checker] SLF4J: Defaulting to no-operation (NOP) logger implementation
[wc-checker] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
[wc-checker] Checking working copy status...

-jenkins-base:

BUILD SUCCESSFUL
Total time: 217 minutes 49 seconds
Archiving artifacts
WARN: No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
WARN: java.lang.InterruptedException: no matches found within 10000
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)