You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2018/03/14 23:33:21 UTC
[JENKINS] Lucene-Solr-7.x-Solaris (64bit/jdk1.8.0) - Build # 493 -
Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/493/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseParallelGC
2 tests failed.
FAILED: org.apache.solr.cloud.MoveReplicaHDFSTest.testFailedMove
Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:50617/solr/MoveReplicaHDFSTest_failed_coll_true, http://127.0.0.1:41003/solr/MoveReplicaHDFSTest_failed_coll_true]
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:50617/solr/MoveReplicaHDFSTest_failed_coll_true, http://127.0.0.1:41003/solr/MoveReplicaHDFSTest_failed_coll_true]
at __randomizedtesting.SeedInfo.seed([1EF46114A7261B3A:B439B2E610F5CEEA]:0)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:462)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1105)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:885)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:992)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:818)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:942)
at org.apache.solr.cloud.MoveReplicaTest.testFailedMove(MoveReplicaTest.java:307)
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)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:41003/solr/MoveReplicaHDFSTest_failed_coll_true: no servers hosting shard: shard2
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:436)
... 46 more
FAILED: org.apache.solr.cloud.MoveReplicaHDFSTest.testFailedMove
Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:42398/solr/MoveReplicaHDFSTest_failed_coll_true, http://127.0.0.1:57063/solr/MoveReplicaHDFSTest_failed_coll_true]
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:42398/solr/MoveReplicaHDFSTest_failed_coll_true, http://127.0.0.1:57063/solr/MoveReplicaHDFSTest_failed_coll_true]
at __randomizedtesting.SeedInfo.seed([1EF46114A7261B3A:B439B2E610F5CEEA]:0)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:462)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1105)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:885)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:992)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:818)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:942)
at org.apache.solr.cloud.MoveReplicaTest.testFailedMove(MoveReplicaTest.java:307)
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)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:57063/solr/MoveReplicaHDFSTest_failed_coll_true: no servers hosting shard: shard2
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:436)
... 46 more
Build Log:
[...truncated 1783 lines...]
[junit4] JVM J1: stdout was not empty, see: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/lucene/build/core/test/temp/junit4-J1-20180314_220202_5809214134048538479459.sysout
[junit4] >>> JVM J1 emitted unexpected output (verbatim) ----
[junit4] codec: SimpleText, pf: LuceneVarGapFixedInterval, dvf: Asserting
[junit4] <<< JVM J1: EOF ----
[...truncated 10949 lines...]
[junit4] Suite: org.apache.solr.cloud.MoveReplicaHDFSTest
[junit4] 2> 713051 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/init-core-data-001
[junit4] 2> 713052 WARN (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=120 numCloses=120
[junit4] 2> 713052 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 713054 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 713054 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-001
[junit4] 2> 713054 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 713054 INFO (Thread-1992) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 713054 INFO (Thread-1992) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 713055 ERROR (Thread-1992) [ ] 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> 713154 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:62505
[junit4] 2> 713157 INFO (zkConnectionManagerCallback-4129-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713163 INFO (jetty-launcher-4126-thread-2) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T03:27:37+06:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 713163 INFO (jetty-launcher-4126-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T03:27:37+06:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 713163 INFO (jetty-launcher-4126-thread-3) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T03:27:37+06:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 713164 INFO (jetty-launcher-4126-thread-4) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T03:27:37+06:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 713164 INFO (jetty-launcher-4126-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 713164 INFO (jetty-launcher-4126-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 713164 INFO (jetty-launcher-4126-thread-2) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 713165 INFO (jetty-launcher-4126-thread-4) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 713165 INFO (jetty-launcher-4126-thread-4) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 713165 INFO (jetty-launcher-4126-thread-4) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 713166 INFO (jetty-launcher-4126-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4edd1e29{/solr,null,AVAILABLE}
[junit4] 2> 713167 INFO (jetty-launcher-4126-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@56f7fde6{/solr,null,AVAILABLE}
[junit4] 2> 713167 INFO (jetty-launcher-4126-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@43e71462{HTTP/1.1,[http/1.1]}{127.0.0.1:48736}
[junit4] 2> 713167 INFO (jetty-launcher-4126-thread-2) [ ] o.e.j.s.Server Started @715524ms
[junit4] 2> 713167 INFO (jetty-launcher-4126-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=48736}
[junit4] 2> 713167 INFO (jetty-launcher-4126-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 713167 INFO (jetty-launcher-4126-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 713167 INFO (jetty-launcher-4126-thread-1) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 713167 ERROR (jetty-launcher-4126-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 713167 INFO (jetty-launcher-4126-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 713167 INFO (jetty-launcher-4126-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.4.0
[junit4] 2> 713167 INFO (jetty-launcher-4126-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 713167 INFO (jetty-launcher-4126-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 713167 INFO (jetty-launcher-4126-thread-3) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 713168 INFO (jetty-launcher-4126-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 713168 INFO (jetty-launcher-4126-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-14T22:29:19.813Z
[junit4] 2> 713168 INFO (jetty-launcher-4126-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1b99fee4{/solr,null,AVAILABLE}
[junit4] 2> 713168 INFO (jetty-launcher-4126-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@76c30c63{HTTP/1.1,[http/1.1]}{127.0.0.1:42398}
[junit4] 2> 713168 INFO (jetty-launcher-4126-thread-3) [ ] o.e.j.s.Server Started @715525ms
[junit4] 2> 713168 INFO (jetty-launcher-4126-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42398}
[junit4] 2> 713168 ERROR (jetty-launcher-4126-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 713168 INFO (jetty-launcher-4126-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.4.0
[junit4] 2> 713168 INFO (jetty-launcher-4126-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 713168 INFO (jetty-launcher-4126-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 713168 INFO (jetty-launcher-4126-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-14T22:29:19.813Z
[junit4] 2> 713169 INFO (jetty-launcher-4126-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@aa9c697{HTTP/1.1,[http/1.1]}{127.0.0.1:53487}
[junit4] 2> 713169 INFO (jetty-launcher-4126-thread-4) [ ] o.e.j.s.Server Started @715526ms
[junit4] 2> 713169 INFO (jetty-launcher-4126-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=53487}
[junit4] 2> 713169 ERROR (jetty-launcher-4126-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 713169 INFO (jetty-launcher-4126-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.4.0
[junit4] 2> 713169 INFO (jetty-launcher-4126-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 713169 INFO (jetty-launcher-4126-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 713169 INFO (jetty-launcher-4126-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-14T22:29:19.814Z
[junit4] 2> 713170 INFO (jetty-launcher-4126-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@773f3e41{/solr,null,AVAILABLE}
[junit4] 2> 713170 INFO (jetty-launcher-4126-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6984db08{HTTP/1.1,[http/1.1]}{127.0.0.1:42543}
[junit4] 2> 713170 INFO (jetty-launcher-4126-thread-1) [ ] o.e.j.s.Server Started @715527ms
[junit4] 2> 713170 INFO (jetty-launcher-4126-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42543}
[junit4] 2> 713170 ERROR (jetty-launcher-4126-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 713170 INFO (jetty-launcher-4126-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.4.0
[junit4] 2> 713170 INFO (jetty-launcher-4126-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 713170 INFO (jetty-launcher-4126-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 713170 INFO (jetty-launcher-4126-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-14T22:29:19.815Z
[junit4] 2> 713171 INFO (zkConnectionManagerCallback-4131-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713171 INFO (zkConnectionManagerCallback-4133-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713172 INFO (zkConnectionManagerCallback-4135-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713172 INFO (jetty-launcher-4126-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 713172 INFO (jetty-launcher-4126-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 713172 INFO (zkConnectionManagerCallback-4137-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713172 INFO (jetty-launcher-4126-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 713173 INFO (jetty-launcher-4126-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 713179 INFO (jetty-launcher-4126-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62505/solr
[junit4] 2> 713179 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 0x1000294f8460001, likely client has closed socket
[junit4] 2> 713180 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 0x1000294f8460002, likely client has closed socket
[junit4] 2> 713180 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 0x1000294f8460003, likely client has closed socket
[junit4] 2> 713181 INFO (jetty-launcher-4126-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62505/solr
[junit4] 2> 713182 INFO (zkConnectionManagerCallback-4141-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713182 INFO (zkConnectionManagerCallback-4146-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713183 INFO (jetty-launcher-4126-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62505/solr
[junit4] 2> 713184 INFO (jetty-launcher-4126-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62505/solr
[junit4] 2> 713186 INFO (zkConnectionManagerCallback-4149-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713187 INFO (zkConnectionManagerCallback-4153-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713187 INFO (zkConnectionManagerCallback-4155-thread-1-processing-n:127.0.0.1:53487_solr) [n:127.0.0.1:53487_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713187 INFO (zkConnectionManagerCallback-4157-thread-1-processing-n:127.0.0.1:48736_solr) [n:127.0.0.1:48736_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713189 INFO (zkConnectionManagerCallback-4159-thread-1-processing-n:127.0.0.1:42398_solr) [n:127.0.0.1:42398_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713190 INFO (zkConnectionManagerCallback-4161-thread-1-processing-n:127.0.0.1:42543_solr) [n:127.0.0.1:42543_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713247 INFO (jetty-launcher-4126-thread-4) [n:127.0.0.1:53487_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 713248 INFO (jetty-launcher-4126-thread-4) [n:127.0.0.1:53487_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:53487_solr
[junit4] 2> 713249 INFO (jetty-launcher-4126-thread-1) [n:127.0.0.1:42543_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 713249 INFO (jetty-launcher-4126-thread-4) [n:127.0.0.1:53487_solr ] o.a.s.c.Overseer Overseer (id=72060432881680393-127.0.0.1:53487_solr-n_0000000000) starting
[junit4] 2> 713256 INFO (jetty-launcher-4126-thread-2) [n:127.0.0.1:48736_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 713263 INFO (jetty-launcher-4126-thread-1) [n:127.0.0.1:42543_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42543_solr
[junit4] 2> 713263 INFO (jetty-launcher-4126-thread-2) [n:127.0.0.1:48736_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48736_solr
[junit4] 2> 713265 INFO (zkCallback-4160-thread-1-processing-n:127.0.0.1:42543_solr) [n:127.0.0.1:42543_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 713266 INFO (zkCallback-4154-thread-1-processing-n:127.0.0.1:53487_solr) [n:127.0.0.1:53487_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 713266 INFO (zkConnectionManagerCallback-4169-thread-1-processing-n:127.0.0.1:53487_solr) [n:127.0.0.1:53487_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713267 INFO (zkCallback-4156-thread-1-processing-n:127.0.0.1:48736_solr) [n:127.0.0.1:48736_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 713268 INFO (zkCallback-4160-thread-1-processing-n:127.0.0.1:42543_solr) [n:127.0.0.1:42543_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 713268 INFO (jetty-launcher-4126-thread-4) [n:127.0.0.1:53487_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 713268 INFO (zkCallback-4154-thread-1-processing-n:127.0.0.1:53487_solr) [n:127.0.0.1:53487_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 713269 INFO (jetty-launcher-4126-thread-4) [n:127.0.0.1:53487_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62505/solr ready
[junit4] 2> 713273 INFO (jetty-launcher-4126-thread-4) [n:127.0.0.1:53487_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53487_solr
[junit4] 2> 713282 INFO (zkCallback-4168-thread-1-processing-n:127.0.0.1:53487_solr) [n:127.0.0.1:53487_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 713286 INFO (zkCallback-4154-thread-1-processing-n:127.0.0.1:53487_solr) [n:127.0.0.1:53487_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 713286 INFO (zkCallback-4160-thread-1-processing-n:127.0.0.1:42543_solr) [n:127.0.0.1:42543_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 713286 INFO (zkCallback-4156-thread-1-processing-n:127.0.0.1:48736_solr) [n:127.0.0.1:48736_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 713327 INFO (jetty-launcher-4126-thread-3) [n:127.0.0.1:42398_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 713329 INFO (jetty-launcher-4126-thread-3) [n:127.0.0.1:42398_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 713331 INFO (jetty-launcher-4126-thread-3) [n:127.0.0.1:42398_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42398_solr
[junit4] 2> 713342 INFO (zkCallback-4160-thread-1-processing-n:127.0.0.1:42543_solr) [n:127.0.0.1:42543_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 713343 INFO (zkCallback-4158-thread-1-processing-n:127.0.0.1:42398_solr) [n:127.0.0.1:42398_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 713343 INFO (zkCallback-4156-thread-1-processing-n:127.0.0.1:48736_solr) [n:127.0.0.1:48736_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 713343 INFO (zkCallback-4168-thread-1-processing-n:127.0.0.1:53487_solr) [n:127.0.0.1:53487_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 713343 INFO (zkCallback-4154-thread-1-processing-n:127.0.0.1:53487_solr) [n:127.0.0.1:53487_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 713405 INFO (jetty-launcher-4126-thread-1) [n:127.0.0.1:42543_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42543.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 713410 INFO (jetty-launcher-4126-thread-1) [n:127.0.0.1:42543_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42543.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 713410 INFO (jetty-launcher-4126-thread-1) [n:127.0.0.1:42543_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42543.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 713411 INFO (jetty-launcher-4126-thread-1) [n:127.0.0.1:42543_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-001/node2/.
[junit4] 2> 713417 INFO (zkConnectionManagerCallback-4173-thread-1-processing-n:127.0.0.1:42543_solr) [n:127.0.0.1:42543_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713442 INFO (jetty-launcher-4126-thread-1) [n:127.0.0.1:42543_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 713442 INFO (jetty-launcher-4126-thread-1) [n:127.0.0.1:42543_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62505/solr ready
[junit4] 2> 713461 INFO (jetty-launcher-4126-thread-2) [n:127.0.0.1:48736_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_48736.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 713461 INFO (jetty-launcher-4126-thread-3) [n:127.0.0.1:42398_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42398.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 713467 INFO (jetty-launcher-4126-thread-2) [n:127.0.0.1:48736_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_48736.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 713467 INFO (jetty-launcher-4126-thread-3) [n:127.0.0.1:42398_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42398.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 713467 INFO (jetty-launcher-4126-thread-2) [n:127.0.0.1:48736_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_48736.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 713467 INFO (jetty-launcher-4126-thread-3) [n:127.0.0.1:42398_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42398.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 713468 INFO (jetty-launcher-4126-thread-2) [n:127.0.0.1:48736_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-001/node1/.
[junit4] 2> 713468 INFO (jetty-launcher-4126-thread-3) [n:127.0.0.1:42398_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-001/node3/.
[junit4] 2> 713471 INFO (zkConnectionManagerCallback-4178-thread-1-processing-n:127.0.0.1:48736_solr) [n:127.0.0.1:48736_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713473 INFO (jetty-launcher-4126-thread-2) [n:127.0.0.1:48736_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 713474 INFO (jetty-launcher-4126-thread-2) [n:127.0.0.1:48736_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62505/solr ready
[junit4] 2> 713475 INFO (zkConnectionManagerCallback-4181-thread-1-processing-n:127.0.0.1:42398_solr) [n:127.0.0.1:42398_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713476 INFO (jetty-launcher-4126-thread-3) [n:127.0.0.1:42398_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 713477 INFO (jetty-launcher-4126-thread-3) [n:127.0.0.1:42398_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62505/solr ready
[junit4] 2> 713546 INFO (jetty-launcher-4126-thread-4) [n:127.0.0.1:53487_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_53487.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 713550 INFO (jetty-launcher-4126-thread-4) [n:127.0.0.1:53487_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_53487.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 713550 INFO (jetty-launcher-4126-thread-4) [n:127.0.0.1:53487_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_53487.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 713551 INFO (jetty-launcher-4126-thread-4) [n:127.0.0.1:53487_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-001/node4/.
[junit4] 2> 713576 INFO (zkConnectionManagerCallback-4183-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713581 INFO (zkConnectionManagerCallback-4187-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 713582 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 713584 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62505/solr ready
[junit4] 2> 713590 INFO (qtp530344848-10965) [n:127.0.0.1:42543_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 713599 INFO (qtp530344848-10965) [n:127.0.0.1:42543_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=9
[junit4] 1> Formatting using clusterid: testClusterID
[junit4] 2> 713737 WARN (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
[junit4] 2> 713748 WARN (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 713750 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 713761 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.m.log Extract jar:file:/export/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/hdfs to ./temp/Jetty_serv1.vm3_56288_hdfs____5yg52q/webapp
[junit4] 2> 714311 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@serv1-vm3:56288
[junit4] 2> 714579 WARN (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 714580 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 714590 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.m.log Extract jar:file:/export/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_34263_datanode____d5nr6d/webapp
[junit4] 2> 715057 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:34263
[junit4] 2> 715186 WARN (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 715187 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 715198 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.m.log Extract jar:file:/export/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_61363_datanode____.bhycxw/webapp
[junit4] 2> 715373 ERROR (DataNode: [[[DISK]file:/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-002/hdfsBaseDir/data/data1/, [DISK]file:/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-002/hdfsBaseDir/data/data2/]] heartbeating to serv1-vm3/127.0.0.1:46117) [ ] o.a.h.h.s.d.DirectoryScanner dfs.datanode.directoryscan.throttle.limit.ms.per.sec set to value below 1 ms/sec. Assuming default value of 1000
[junit4] 2> 715382 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0x2766240f34a9: from storage DS-53dd4170-7aa4-421c-ace1-590ef9a3e5c0 node DatanodeRegistration(127.0.0.1:52373, datanodeUuid=95bb9b04-86bf-4cfa-8554-9cf7aa85d7a8, infoPort=36741, infoSecurePort=0, ipcPort=61439, storageInfo=lv=-56;cid=testClusterID;nsid=456451132;c=0), blocks: 0, hasStaleStorage: true, processing time: 0 msecs
[junit4] 2> 715382 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0x2766240f34a9: from storage DS-048d9d8d-3848-4ceb-a093-69a1af727e67 node DatanodeRegistration(127.0.0.1:52373, datanodeUuid=95bb9b04-86bf-4cfa-8554-9cf7aa85d7a8, infoPort=36741, infoSecurePort=0, ipcPort=61439, storageInfo=lv=-56;cid=testClusterID;nsid=456451132;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs
[junit4] 2> 715596 INFO (OverseerCollectionConfigSetProcessor-72060432881680393-127.0.0.1:53487_solr-n_0000000000) [n:127.0.0.1:53487_solr ] 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> 715680 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:61363
[junit4] 2> 715902 ERROR (DataNode: [[[DISK]file:/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-002/hdfsBaseDir/data/data3/, [DISK]file:/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-002/hdfsBaseDir/data/data4/]] heartbeating to serv1-vm3/127.0.0.1:46117) [ ] o.a.h.h.s.d.DirectoryScanner dfs.datanode.directoryscan.throttle.limit.ms.per.sec set to value below 1 ms/sec. Assuming default value of 1000
[junit4] 2> 715909 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0x2766437eb75e: from storage DS-5b362fca-8c81-4967-b2ad-4911621baa22 node DatanodeRegistration(127.0.0.1:48880, datanodeUuid=23c37fec-41f4-45a8-98f1-2f1576179b5a, infoPort=51153, infoSecurePort=0, ipcPort=38899, storageInfo=lv=-56;cid=testClusterID;nsid=456451132;c=0), blocks: 0, hasStaleStorage: true, processing time: 0 msecs
[junit4] 2> 715910 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0x2766437eb75e: from storage DS-f6e146a0-ece1-460e-a010-1dadb530841e node DatanodeRegistration(127.0.0.1:48880, datanodeUuid=23c37fec-41f4-45a8-98f1-2f1576179b5a, infoPort=51153, infoSecurePort=0, ipcPort=38899, storageInfo=lv=-56;cid=testClusterID;nsid=456451132;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs
[junit4] 2> 716104 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 716106 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 716108 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T03:27:37+06:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 716109 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 716109 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 716109 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 716109 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@22c6ab04{/solr,null,AVAILABLE}
[junit4] 2> 716109 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@c0605e6{HTTP/1.1,[http/1.1]}{127.0.0.1:57063}
[junit4] 2> 716109 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.e.j.s.Server Started @718467ms
[junit4] 2> 716109 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=57063}
[junit4] 2> 716109 ERROR (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 716110 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.4.0
[junit4] 2> 716110 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 716110 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 716110 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-14T22:29:22.755Z
[junit4] 2> 716111 INFO (zkConnectionManagerCallback-4190-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 716112 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 716118 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62505/solr
[junit4] 2> 716119 INFO (zkConnectionManagerCallback-4194-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 716123 INFO (zkConnectionManagerCallback-4196-thread-1-processing-n:127.0.0.1:57063_solr) [n:127.0.0.1:57063_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 716133 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [n:127.0.0.1:57063_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 716137 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [n:127.0.0.1:57063_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 716140 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [n:127.0.0.1:57063_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57063_solr
[junit4] 2> 716142 INFO (zkCallback-4154-thread-1-processing-n:127.0.0.1:53487_solr) [n:127.0.0.1:53487_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 716143 INFO (zkCallback-4158-thread-1-processing-n:127.0.0.1:42398_solr) [n:127.0.0.1:42398_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 716143 INFO (zkCallback-4160-thread-1-processing-n:127.0.0.1:42543_solr) [n:127.0.0.1:42543_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 716143 INFO (zkCallback-4156-thread-1-processing-n:127.0.0.1:48736_solr) [n:127.0.0.1:48736_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 716143 INFO (zkCallback-4172-thread-1-processing-n:127.0.0.1:42543_solr) [n:127.0.0.1:42543_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 716144 INFO (zkCallback-4168-thread-1-processing-n:127.0.0.1:53487_solr) [n:127.0.0.1:53487_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 716144 INFO (zkCallback-4186-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 716145 INFO (zkCallback-4186-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 716145 INFO (zkCallback-4177-thread-1-processing-n:127.0.0.1:48736_solr) [n:127.0.0.1:48736_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 716145 INFO (zkCallback-4180-thread-1-processing-n:127.0.0.1:42398_solr) [n:127.0.0.1:42398_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 716146 INFO (zkCallback-4195-thread-1-processing-n:127.0.0.1:57063_solr) [n:127.0.0.1:57063_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 716202 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [n:127.0.0.1:57063_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57063.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 716218 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [n:127.0.0.1:57063_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57063.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 716218 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [n:127.0.0.1:57063_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57063.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 716219 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [n:127.0.0.1:57063_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-001/node5/.
[junit4] 2> 716222 INFO (zkConnectionManagerCallback-4201-thread-1-processing-n:127.0.0.1:57063_solr) [n:127.0.0.1:57063_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 716225 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [n:127.0.0.1:57063_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5)
[junit4] 2> 716227 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [n:127.0.0.1:57063_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62505/solr ready
[junit4] 2> 716271 INFO (zkConnectionManagerCallback-4203-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 716273 INFO (TEST-MoveReplicaHDFSTest.test-seed#[1EF46114A7261B3A]) [ ] o.a.s.c.MoveReplicaTest total_jettys: 5
[junit4] 2> 716275 INFO (qtp222522934-10968) [n:127.0.0.1:42398_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf1&maxShardsPerNode=2&autoAddReplicas=false&name=MoveReplicaHDFSTest_coll_true&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 716278 INFO (OverseerThreadFactory-3244-thread-2-processing-n:127.0.0.1:53487_solr) [n:127.0.0.1:53487_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection MoveReplicaHDFSTest_coll_true
[junit4] 2> 716392 INFO (OverseerStateUpdate-72060432881680393-127.0.0.1:53487_solr-n_0000000000) [n:127.0.0.1:53487_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"MoveReplicaHDFSTest_coll_true",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"MoveReplicaHDFSTest_coll_true_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:42398/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 716395 INFO (OverseerStateUpdate-72060432881680393-127.0.0.1:53487_solr-n_0000000000) [n:127.0.0.1:53487_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"MoveReplicaHDFSTest_coll_true",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"MoveReplicaHDFSTest_coll_true_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:57063/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 716400 INFO (OverseerStateUpdate-72060432881680393-127.0.0.1:53487_solr-n_0000000000) [n:127.0.0.1:53487_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"MoveReplicaHDFSTest_coll_true",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"MoveReplicaHDFSTest_coll_true_shard2_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:42543/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 716403 INFO (OverseerStateUpdate-72060432881680393-127.0.0.1:53487_solr-n_0000000000) [n:127.0.0.1:53487_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"MoveReplicaHDFSTest_coll_true",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"MoveReplicaHDFSTest_coll_true_shard2_replica_n6",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:48736/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 716607 INFO (qtp222522934-10983) [n:127.0.0.1:42398_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf1&newCollection=true&name=MoveReplicaHDFSTest_coll_true_shard1_replica_n1&action=CREATE&numShards=2&collection=MoveReplicaHDFSTest_coll_true&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 716607 INFO (qtp222522934-10983) [n:127.0.0.1:42398_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 716607 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf1&newCollection=true&name=MoveReplicaHDFSTest_coll_true_shard2_replica_n4&action=CREATE&numShards=2&collection=MoveReplicaHDFSTest_coll_true&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 716607 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 716608 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf1&newCollection=true&name=MoveReplicaHDFSTest_coll_true_shard2_replica_n6&action=CREATE&numShards=2&collection=MoveReplicaHDFSTest_coll_true&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 716608 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 716615 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf1&newCollection=true&name=MoveReplicaHDFSTest_coll_true_shard1_replica_n2&action=CREATE&numShards=2&collection=MoveReplicaHDFSTest_coll_true&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 716616 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 716722 INFO (zkCallback-4156-thread-1-processing-n:127.0.0.1:48736_solr) [n:127.0.0.1:48736_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 716722 INFO (zkCallback-4160-thread-1-processing-n:127.0.0.1:42543_solr) [n:127.0.0.1:42543_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 716722 INFO (zkCallback-4158-thread-1-processing-n:127.0.0.1:42398_solr) [n:127.0.0.1:42398_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 716722 INFO (zkCallback-4156-thread-2-processing-n:127.0.0.1:48736_solr) [n:127.0.0.1:48736_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 716722 INFO (zkCallback-4160-thread-2-processing-n:127.0.0.1:42543_solr) [n:127.0.0.1:42543_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 716723 INFO (zkCallback-4158-thread-2-processing-n:127.0.0.1:42398_solr) [n:127.0.0.1:42398_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 716723 INFO (zkCallback-4195-thread-1-processing-n:127.0.0.1:57063_solr) [n:127.0.0.1:57063_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 716723 INFO (zkCallback-4195-thread-2-processing-n:127.0.0.1:57063_solr) [n:127.0.0.1:57063_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 717621 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 717621 INFO (qtp222522934-10983) [n:127.0.0.1:42398_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node3 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 717625 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 717627 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.s.IndexSchema [MoveReplicaHDFSTest_coll_true_shard2_replica_n6] Schema name=minimal
[junit4] 2> 717629 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 717629 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.c.CoreContainer Creating SolrCore 'MoveReplicaHDFSTest_coll_true_shard2_replica_n6' using configuration from collection MoveReplicaHDFSTest_coll_true, trusted=true
[junit4] 2> 717629 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_48736.solr.core.MoveReplicaHDFSTest_coll_true.shard2.replica_n6' (registry 'solr.core.MoveReplicaHDFSTest_coll_true.shard2.replica_n6') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 717630 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.s.IndexSchema [MoveReplicaHDFSTest_coll_true_shard2_replica_n4] Schema name=minimal
[junit4] 2> 717630 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 717641 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 717641 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.c.CoreContainer Creating SolrCore 'MoveReplicaHDFSTest_coll_true_shard2_replica_n4' using configuration from collection MoveReplicaHDFSTest_coll_true, trusted=true
[junit4] 2> 717641 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42543.solr.core.MoveReplicaHDFSTest_coll_true.shard2.replica_n4' (registry 'solr.core.MoveReplicaHDFSTest_coll_true.shard2.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 717643 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://serv1-vm3:46117/data
[junit4] 2> 717643 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 717643 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 717643 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.c.SolrCore [[MoveReplicaHDFSTest_coll_true_shard2_replica_n6] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-001/node1/MoveReplicaHDFSTest_coll_true_shard2_replica_n6], dataDir=[hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node8/data/]
[junit4] 2> 717643 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.s.IndexSchema [MoveReplicaHDFSTest_coll_true_shard1_replica_n2] Schema name=minimal
[junit4] 2> 717644 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node8/data/snapshot_metadata
[junit4] 2> 717644 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://serv1-vm3:46117/data
[junit4] 2> 717644 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 717644 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 717644 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.c.SolrCore [[MoveReplicaHDFSTest_coll_true_shard2_replica_n4] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-001/node2/MoveReplicaHDFSTest_coll_true_shard2_replica_n4], dataDir=[hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node7/data/]
[junit4] 2> 717645 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 717645 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'MoveReplicaHDFSTest_coll_true_shard1_replica_n2' using configuration from collection MoveReplicaHDFSTest_coll_true, trusted=true
[junit4] 2> 717645 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node7/data/snapshot_metadata
[junit4] 2> 717645 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57063.solr.core.MoveReplicaHDFSTest_coll_true.shard1.replica_n2' (registry 'solr.core.MoveReplicaHDFSTest_coll_true.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 717645 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://serv1-vm3:46117/data
[junit4] 2> 717645 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 717645 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 717645 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.c.SolrCore [[MoveReplicaHDFSTest_coll_true_shard1_replica_n2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-001/node5/MoveReplicaHDFSTest_coll_true_shard1_replica_n2], dataDir=[hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node5/data/]
[junit4] 2> 717646 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node5/data/snapshot_metadata
[junit4] 2> 717647 INFO (qtp222522934-10983) [n:127.0.0.1:42398_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node3 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n1] o.a.s.s.IndexSchema [MoveReplicaHDFSTest_coll_true_shard1_replica_n1] Schema name=minimal
[junit4] 2> 717649 INFO (qtp222522934-10983) [n:127.0.0.1:42398_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node3 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 717649 INFO (qtp222522934-10983) [n:127.0.0.1:42398_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node3 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'MoveReplicaHDFSTest_coll_true_shard1_replica_n1' using configuration from collection MoveReplicaHDFSTest_coll_true, trusted=true
[junit4] 2> 717649 INFO (qtp222522934-10983) [n:127.0.0.1:42398_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node3 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42398.solr.core.MoveReplicaHDFSTest_coll_true.shard1.replica_n1' (registry 'solr.core.MoveReplicaHDFSTest_coll_true.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25b210f2
[junit4] 2> 717649 INFO (qtp222522934-10983) [n:127.0.0.1:42398_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node3 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n1] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://serv1-vm3:46117/data
[junit4] 2> 717649 INFO (qtp222522934-10983) [n:127.0.0.1:42398_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node3 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n1] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 717649 INFO (qtp222522934-10983) [n:127.0.0.1:42398_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node3 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 717649 INFO (qtp222522934-10983) [n:127.0.0.1:42398_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node3 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n1] o.a.s.c.SolrCore [[MoveReplicaHDFSTest_coll_true_shard1_replica_n1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-001/node3/MoveReplicaHDFSTest_coll_true_shard1_replica_n1], dataDir=[hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node3/data/]
[junit4] 2> 717650 INFO (qtp222522934-10983) [n:127.0.0.1:42398_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node3 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node3/data/snapshot_metadata
[junit4] 2> 717675 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node8/data
[junit4] 2> 717685 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node5/data
[junit4] 2> 717687 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node7/data
[junit4] 2> 717688 INFO (qtp222522934-10983) [n:127.0.0.1:42398_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node3 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node3/data
[junit4] 2> 717712 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node5/data/index
[junit4] 2> 717737 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node8/data/index
[junit4] 2> 717752 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node7/data/index
[junit4] 2> 717770 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:52373 is added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-f6e146a0-ece1-460e-a010-1dadb530841e:NORMAL:127.0.0.1:48880|RBW], ReplicaUC[[DISK]DS-048d9d8d-3848-4ceb-a093-69a1af727e67:NORMAL:127.0.0.1:52373|RBW]]} size 0
[junit4] 2> 717777 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48880 is added to blk_1073741825_1001 size 69
[junit4] 2> 717809 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:52373 is added to blk_1073741826_1002{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-5b362fca-8c81-4967-b2ad-4911621baa22:NORMAL:127.0.0.1:48880|RBW], ReplicaUC[[DISK]DS-53dd4170-7aa4-421c-ace1-590ef9a3e5c0:NORMAL:127.0.0.1:52373|RBW]]} size 69
[junit4] 2> 717809 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48880 is added to blk_1073741826_1002 size 69
[junit4] 2> 717821 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48880 is added to blk_1073741827_1003{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-53dd4170-7aa4-421c-ace1-590ef9a3e5c0:NORMAL:127.0.0.1:52373|RBW], ReplicaUC[[DISK]DS-f6e146a0-ece1-460e-a010-1dadb530841e:NORMAL:127.0.0.1:48880|RBW]]} size 0
[junit4] 2> 717824 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:52373 is added to blk_1073741827_1003{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-f6e146a0-ece1-460e-a010-1dadb530841e:NORMAL:127.0.0.1:48880|RBW], ReplicaUC[[DISK]DS-048d9d8d-3848-4ceb-a093-69a1af727e67:NORMAL:127.0.0.1:52373|FINALIZED]]} size 0
[junit4] 2> 717836 INFO (qtp222522934-10983) [n:127.0.0.1:42398_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node3 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://serv1-vm3:46117/data/MoveReplicaHDFSTest_coll_true/core_node3/data/index
[junit4] 2> 717848 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 717848 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 717849 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
[junit4] 2> 717862 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 717862 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 717863 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:52373 is added to blk_1073741828_1004{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-5b362fca-8c81-4967-b2ad-4911621baa22:NORMAL:127.0.0.1:48880|RBW], ReplicaUC[[DISK]DS-048d9d8d-3848-4ceb-a093-69a1af727e67:NORMAL:127.0.0.1:52373|RBW]]} size 69
[junit4] 2> 717863 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48880 is added to blk_1073741828_1004 size 69
[junit4] 2> 717879 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@703c49f1[MoveReplicaHDFSTest_coll_true_shard1_replica_n2] main]
[junit4] 2> 717881 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 717881 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 717882 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 717883 INFO (searcherExecutor-3261-thread-1-processing-n:127.0.0.1:57063_solr x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2 s:shard1 c:MoveReplicaHDFSTest_coll_true r:core_node5) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.c.SolrCore [MoveReplicaHDFSTest_coll_true_shard1_replica_n2] Registered new searcher Searcher@703c49f1[MoveReplicaHDFSTest_coll_true_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 717883 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1594953893966512128
[junit4] 2> 717888 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.c.ZkShardTerms Successful update terms at /collections/MoveReplicaHDFSTest_coll_true/terms/shard1 to Terms{values={core_node5=0}, version=0}
[junit4] 2> 717894 INFO (qtp61732690-11238) [n:127.0.0.1:57063_solr c:MoveReplicaHDFSTest_coll_true s:shard1 r:core_node5 x:MoveReplicaHDFSTest_coll_true_shard1_replica_n2] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 717895 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 717895 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 717895 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
[junit4] 2> 717904 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 717904 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 717916 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.s.SolrIndexSearcher Opening [Searcher@2aba9d01[MoveReplicaHDFSTest_coll_true_shard2_replica_n4] main]
[junit4] 2> 717918 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 717918 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 717918 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 717919 INFO (searcherExecutor-3260-thread-1-processing-n:127.0.0.1:42543_solr x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4 s:shard2 c:MoveReplicaHDFSTest_coll_true r:core_node7) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.c.SolrCore [MoveReplicaHDFSTest_coll_true_shard2_replica_n4] Registered new searcher Searcher@2aba9d01[MoveReplicaHDFSTest_coll_true_shard2_replica_n4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 717919 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1594953894004260864
[junit4] 2> 717923 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.c.ZkShardTerms Successful update terms at /collections/MoveReplicaHDFSTest_coll_true/terms/shard2 to Terms{values={core_node7=0}, version=0}
[junit4] 2> 717929 INFO (qtp530344848-10988) [n:127.0.0.1:42543_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node7 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms
[junit4] 2> 718030 INFO (zkCallback-4156-thread-1-processing-n:127.0.0.1:48736_solr) [n:127.0.0.1:48736_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 718030 INFO (zkCallback-4195-thread-2-processing-n:127.0.0.1:57063_solr) [n:127.0.0.1:57063_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 718030 INFO (zkCallback-4158-thread-2-processing-n:127.0.0.1:42398_solr) [n:127.0.0.1:42398_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 718030 INFO (zkCallback-4156-thread-2-processing-n:127.0.0.1:48736_solr) [n:127.0.0.1:48736_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 718030 INFO (zkCallback-4158-thread-1-processing-n:127.0.0.1:42398_solr) [n:127.0.0.1:42398_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 718031 INFO (zkCallback-4195-thread-1-processing-n:127.0.0.1:57063_solr) [n:127.0.0.1:57063_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 718031 INFO (zkCallback-4160-thread-2-processing-n:127.0.0.1:42543_solr) [n:127.0.0.1:42543_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 718031 INFO (zkCallback-4160-thread-1-processing-n:127.0.0.1:42543_solr) [n:127.0.0.1:42543_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/MoveReplicaHDFSTest_coll_true/state.json] for collection [MoveReplicaHDFSTest_coll_true] has occurred - updating... (live nodes size: [5])
[junit4] 2> 718256 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 718256 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 718256 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
[junit4] 2> 718265 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 718265 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 718302 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@7f80478f[MoveReplicaHDFSTest_coll_true_shard2_replica_n6] main]
[junit4] 2> 718304 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 718304 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 718305 INFO (qtp1518593307-10961) [n:127.0.0.1:48736_solr c:MoveReplicaHDFSTest_coll_true s:shard2 r:core_node8 x:MoveReplicaHDFSTest_coll_true_shard2_replica_n6] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 718305 INFO (searcherExecu
[...truncated too long message...]
r-236-thread-5) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4424c67a{/solr,null,UNAVAILABLE}
[junit4] 2> 286604 INFO (jetty-closer-236-thread-5) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 286609 INFO (jetty-closer-236-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@d7c7a6d{/solr,null,UNAVAILABLE}
[junit4] 2> 286610 INFO (jetty-closer-236-thread-4) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 286613 ERROR (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 286614 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33599 33599
[junit4] 2> 286750 INFO (Thread-4218) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33599 33599
[junit4] 2> 286755 WARN (Thread-4218) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 31 /solr/collections/MoveReplicaHDFSTest_coll_false/terms/shard2
[junit4] 2> 27 /solr/collections/MoveReplicaHDFSTest_coll_true/terms/shard2
[junit4] 2> 19 /solr/aliases.json
[junit4] 2> 19 /solr/clusterprops.json
[junit4] 2> 18 /solr/configs/conf1
[junit4] 2> 10 /solr/collections/MoveReplicaHDFSTest_failed_coll_false/terms/shard2
[junit4] 2> 8 /solr/collections/MoveReplicaHDFSTest_failed_coll_true/terms/shard1
[junit4] 2> 8 /solr/collections/MoveReplicaHDFSTest_coll_true/terms/shard1
[junit4] 2> 7 /solr/collections/MoveReplicaHDFSTest_failed_coll_true/terms/shard2
[junit4] 2> 7 /solr/security.json
[junit4] 2> 7 /solr/collections/MoveReplicaHDFSTest_coll_false/terms/shard1
[junit4] 2> 7 /solr/collections/MoveReplicaHDFSTest_failed_coll_false/terms/shard1
[junit4] 2> 5 /solr/collections/MoveReplicaHDFSTest_coll_false/collectionprops.json
[junit4] 2> 5 /solr/collections/MoveReplicaHDFSTest_coll_true/collectionprops.json
[junit4] 2> 4 /solr/collections/MoveReplicaHDFSTest_failed_coll_false/collectionprops.json
[junit4] 2> 4 /solr/collections/MoveReplicaHDFSTest_failed_coll_true/collectionprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 70 /solr/collections/MoveReplicaHDFSTest_coll_true/state.json
[junit4] 2> 66 /solr/collections/MoveReplicaHDFSTest_coll_false/state.json
[junit4] 2> 42 /solr/collections/MoveReplicaHDFSTest_failed_coll_false/state.json
[junit4] 2> 37 /solr/collections/MoveReplicaHDFSTest_failed_coll_true/state.json
[junit4] 2> 19 /solr/clusterstate.json
[junit4] 2> 3 /solr/collections/MoveReplicaHDFSTest_coll_false/leader_elect/shard2/election/72060677120589834-core_node8-n_0000000000
[junit4] 2> 3 /solr/autoscaling.json
[junit4] 2> 3 /solr/collections/MoveReplicaHDFSTest_coll_true/leader_elect/shard2/election/72060677120589834-core_node8-n_0000000000
[junit4] 2> 2 /solr/overseer_elect/election/72060677120589834-127.0.0.1:50617_solr-n_0000000002
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 35 /solr/collections
[junit4] 2> 32 /solr/live_nodes
[junit4] 2> 3 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 3 /solr/overseer/collection-queue-work
[junit4] 2> 3 /solr/overseer/queue-work
[junit4] 2> 2 /solr/overseer/queue
[junit4] 2>
[junit4] 2> 286758 WARN (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.h.h.s.d.DirectoryScanner DirectoryScanner: shutdown has been called
[junit4] 2> 286765 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.m.log Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
[junit4] 2> 286869 WARN (DataNode: [[[DISK]file:/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-002/hdfsBaseDir/data/data3/, [DISK]file:/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-002/hdfsBaseDir/data/data4/]] heartbeating to serv1-vm3/127.0.0.1:59900) [ ] o.a.h.h.s.d.IncrementalBlockReportManager IncrementalBlockReportManager interrupted
[junit4] 2> 286869 WARN (DataNode: [[[DISK]file:/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-002/hdfsBaseDir/data/data3/, [DISK]file:/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-002/hdfsBaseDir/data/data4/]] heartbeating to serv1-vm3/127.0.0.1:59900) [ ] o.a.h.h.s.d.DataNode Ending block pool service for: Block pool BP-690988341-127.0.0.1-1521070284841 (Datanode Uuid 803b170c-e8ea-4793-b82c-4513ebfc97e1) service to serv1-vm3/127.0.0.1:59900
[junit4] 2> 286874 WARN (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.h.h.s.d.DirectoryScanner DirectoryScanner: shutdown has been called
[junit4] 2> 286880 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.m.log Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
[junit4] 2> 286985 WARN (DataNode: [[[DISK]file:/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-002/hdfsBaseDir/data/data1/, [DISK]file:/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-002/hdfsBaseDir/data/data2/]] heartbeating to serv1-vm3/127.0.0.1:59900) [ ] o.a.h.h.s.d.IncrementalBlockReportManager IncrementalBlockReportManager interrupted
[junit4] 2> 286985 WARN (DataNode: [[[DISK]file:/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-002/hdfsBaseDir/data/data1/, [DISK]file:/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001/tempDir-002/hdfsBaseDir/data/data2/]] heartbeating to serv1-vm3/127.0.0.1:59900) [ ] o.a.h.h.s.d.DataNode Ending block pool service for: Block pool BP-690988341-127.0.0.1-1521070284841 (Datanode Uuid 0a6c357b-073e-49ff-b278-b4b9dd133b04) service to serv1-vm3/127.0.0.1:59900
[junit4] 2> 287002 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.m.log Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@serv1-vm3:0
[junit4] 2> 287119 INFO (SUITE-MoveReplicaHDFSTest-seed#[1EF46114A7261B3A]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33599 33599
[junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.MoveReplicaHDFSTest_1EF46114A7261B3A-001
[junit4] 2> Mar 14, 2018 11:32:36 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 26 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarity(queryNorm=false): {}, locale=ar-QA, timezone=America/Atka
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_162 (64-bit)/cpus=3,threads=2,free=60537224,total=341835776
[junit4] 2> NOTE: All tests run in this JVM: [MoveReplicaHDFSTest, MoveReplicaHDFSTest, MoveReplicaHDFSTest]
[junit4] Completed [5/5 (1!)] on J0 in 82.33s, 4 tests, 1 error <<< FAILURES!
[...truncated 10 lines...]
BUILD FAILED
/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/lucene/common-build.xml:1561: The following error occurred while executing this line:
/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/lucene/common-build.xml:1085: There were test failures: 5 suites, 20 tests, 1 error [seed: 1EF46114A7261B3A]
Total time: 5 minutes 1 second
[repro] Setting last failure code to 256
[repro] Failures:
[repro] 1/5 failed: org.apache.solr.cloud.MoveReplicaHDFSTest
[repro] Exiting with code 256
+ mv lucene/build lucene/build.repro
+ mv solr/build solr/build.repro
+ mv lucene/build.orig lucene/build
+ mv solr/build.orig solr/build
Archiving artifacts
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[WARNINGS] Parsing warnings in console log with parser Java Compiler (javac)
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
<Git Blamer> Using GitBlamer to create author and commit information for all warnings.
<Git Blamer> GIT_COMMIT=02425b27316caf389554ebf5fe333915cb420289, workspace=/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris
[WARNINGS] Computing warning deltas based on reference build #491
Recording test results
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
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)
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[JENKINS] Lucene-Solr-7.x-Solaris (64bit/jdk1.8.0) - Build # 494 -
Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/494/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.TestDistributedSearch.test
Error Message:
Expected to find shardAddress in the up shard info: {error=org.apache.solr.client.solrj.SolrServerException: Time allowed to handle this request exceeded,trace=org.apache.solr.client.solrj.SolrServerException: Time allowed to handle this request exceeded at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:460) at org.apache.solr.handler.component.HttpShardHandlerFactory.makeLoadBalancedRequest(HttpShardHandlerFactory.java:273) at org.apache.solr.handler.component.HttpShardHandler.lambda$submit$0(HttpShardHandler.java:175) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) ,time=4}
Stack Trace:
java.lang.AssertionError: Expected to find shardAddress in the up shard info: {error=org.apache.solr.client.solrj.SolrServerException: Time allowed to handle this request exceeded,trace=org.apache.solr.client.solrj.SolrServerException: Time allowed to handle this request exceeded
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:460)
at org.apache.solr.handler.component.HttpShardHandlerFactory.makeLoadBalancedRequest(HttpShardHandlerFactory.java:273)
at org.apache.solr.handler.component.HttpShardHandler.lambda$submit$0(HttpShardHandler.java:175)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
,time=4}
at __randomizedtesting.SeedInfo.seed([1100A2614CAEB74A:99549DBBE252DAB2]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.TestDistributedSearch.comparePartialResponses(TestDistributedSearch.java:1191)
at org.apache.solr.TestDistributedSearch.queryPartialResults(TestDistributedSearch.java:1132)
at org.apache.solr.TestDistributedSearch.test(TestDistributedSearch.java:992)
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.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsRepeatStatement.callStatement(BaseDistributedSearchTestCase.java:1019)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:968)
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 1792 lines...]
[junit4] JVM J1: stdout was not empty, see: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/lucene/build/core/test/temp/junit4-J1-20180315_063234_2841402207062093229839.sysout
[junit4] >>> JVM J1 emitted unexpected output (verbatim) ----
[junit4] codec: FastDecompressionCompressingStoredFields, pf: LuceneFixedGap, dvf: Lucene70
[junit4] <<< JVM J1: EOF ----
[...truncated 11000 lines...]
[junit4] Suite: org.apache.solr.TestDistributedSearch
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.TestDistributedSearch_1100A2614CAEB74A-001/init-core-data-001
[junit4] 2> 811421 WARN (SUITE-TestDistributedSearch-seed#[1100A2614CAEB74A]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=21 numCloses=21
[junit4] 2> 811421 INFO (SUITE-TestDistributedSearch-seed#[1100A2614CAEB74A]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 811423 INFO (SUITE-TestDistributedSearch-seed#[1100A2614CAEB74A]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=https://issues.apache.org/jira/browse/SOLR-9061)
[junit4] 2> 811423 INFO (SUITE-TestDistributedSearch-seed#[1100A2614CAEB74A]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 811423 INFO (SUITE-TestDistributedSearch-seed#[1100A2614CAEB74A]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /ets/
[junit4] 2> 811623 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.TestDistributedSearch_1100A2614CAEB74A-001/tempDir-001/control/cores/collection1
[junit4] 2> 811624 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T16:27:37-05:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 811624 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 811624 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 811625 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 811625 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@51fc5d76{/ets,null,AVAILABLE}
[junit4] 2> 811625 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@e5815dd{HTTP/1.1,[http/1.1]}{127.0.0.1:51281}
[junit4] 2> 811626 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.Server Started @814199ms
[junit4] 2> 811626 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/ets, hostPort=51281, coreRootDirectory=/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.TestDistributedSearch_1100A2614CAEB74A-001/tempDir-001/control/cores}
[junit4] 2> 811626 ERROR (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 811626 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.4.0
[junit4] 2> 811626 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 811626 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 811626 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-15T07:01:06.683Z
[junit4] 2> 811627 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.TestDistributedSearch_1100A2614CAEB74A-001/tempDir-001/control/solr.xml
[junit4] 2> 811631 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 811631 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 811632 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@2da6e5e2, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 811675 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da6e5e2
[junit4] 2> 811682 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da6e5e2
[junit4] 2> 811682 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da6e5e2
[junit4] 2> 811683 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.TestDistributedSearch_1100A2614CAEB74A-001/tempDir-001/control/cores
[junit4] 2> 811683 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 811684 INFO (coreLoadExecutor-2996-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 811685 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/core/src/test-files/solr/collection1/lib, /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 811736 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 811752 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 811846 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 811853 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from configset /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/core/src/test-files/solr/collection1, trusted=true
[junit4] 2> 811853 INFO (coreLoadExecutor-2996-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@2da6e5e2
[junit4] 2> 811853 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 811853 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/core/src/test-files/solr/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.TestDistributedSearch_1100A2614CAEB74A-001/tempDir-001/control/cores/collection1/data/]
[junit4] 2> 811854 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=79.0615234375, floorSegmentMB=1.740234375, forceMergeDeletesPctAllowed=13.462939348061614, segmentsPerTier=19.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6902458209418335
[junit4] 2> 811927 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 811928 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 811929 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 811929 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 811930 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=21, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.35741961889174767]
[junit4] 2> 811930 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@261fba1d[collection1] main]
[junit4] 2> 811930 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 812001 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 812074 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 812078 INFO (searcherExecutor-2997-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 812083 INFO (searcherExecutor-2997-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 812083 INFO (searcherExecutor-2997-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 812083 INFO (coreLoadExecutor-2996-thread-1) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1594986087988592640
[junit4] 2> 812083 INFO (searcherExecutor-2997-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 812084 INFO (searcherExecutor-2997-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 812084 INFO (searcherExecutor-2997-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 812085 INFO (searcherExecutor-2997-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 812085 INFO (searcherExecutor-2997-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 812085 INFO (searcherExecutor-2997-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 812087 INFO (searcherExecutor-2997-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@261fba1d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 812280 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.TestDistributedSearch_1100A2614CAEB74A-001/tempDir-001/shard0/cores/collection1
[junit4] 2> 812281 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T16:27:37-05:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 812282 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 812282 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 812282 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 812283 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@691d86{/ets,null,AVAILABLE}
[junit4] 2> 812283 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3d85a4f1{HTTP/1.1,[http/1.1]}{127.0.0.1:41443}
[junit4] 2> 812283 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.Server Started @814857ms
[junit4] 2> 812283 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/ets, hostPort=41443, coreRootDirectory=/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.TestDistributedSearch_1100A2614CAEB74A-001/tempDir-001/shard0/cores}
[junit4] 2> 812284 ERROR (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 812284 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.4.0
[junit4] 2> 812284 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 812284 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 812284 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-15T07:01:07.341Z
[junit4] 2> 812284 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.TestDistributedSearch_1100A2614CAEB74A-001/tempDir-001/shard0/solr.xml
[junit4] 2> 812288 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 812288 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 812289 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@2da6e5e2, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 812329 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da6e5e2
[junit4] 2> 812341 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da6e5e2
[junit4] 2> 812341 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da6e5e2
[junit4] 2> 812343 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.TestDistributedSearch_1100A2614CAEB74A-001/tempDir-001/shard0/cores
[junit4] 2> 812343 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 812344 INFO (coreLoadExecutor-3007-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 812345 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/core/src/test-files/solr/collection1/lib, /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 812383 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 812406 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 812515 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 812525 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from configset /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/core/src/test-files/solr/collection1, trusted=true
[junit4] 2> 812526 INFO (coreLoadExecutor-3007-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@2da6e5e2
[junit4] 2> 812526 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 812526 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/core/src/test-files/solr/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.TestDistributedSearch_1100A2614CAEB74A-001/tempDir-001/shard0/cores/collection1/data/]
[junit4] 2> 812528 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=79.0615234375, floorSegmentMB=1.740234375, forceMergeDeletesPctAllowed=13.462939348061614, segmentsPerTier=19.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6902458209418335
[junit4] 2> 812601 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 812601 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 812604 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 812604 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 812605 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=21, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.35741961889174767]
[junit4] 2> 812606 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5b3560da[collection1] main]
[junit4] 2> 812606 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 812620 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 812696 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 812696 INFO (searcherExecutor-3008-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 812696 INFO (coreLoadExecutor-3007-thread-1) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1594986088631369728
[junit4] 2> 812697 INFO (searcherExecutor-3008-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 812697 INFO (searcherExecutor-3008-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 812697 INFO (searcherExecutor-3008-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 812697 INFO (searcherExecutor-3008-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 812697 INFO (searcherExecutor-3008-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 812697 INFO (searcherExecutor-3008-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 812698 INFO (searcherExecutor-3008-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 812698 INFO (searcherExecutor-3008-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 812699 INFO (searcherExecutor-3008-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5b3560da[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 812699 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 812704 INFO (qtp1787773126-9145) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1594986088637661184)} 0 2
[junit4] 2> 812709 INFO (qtp1283414720-9161) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1594986088643952640)} 0 1
[junit4] 2> 812714 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[1 (1594986088647098368)]} 0 3
[junit4] 2> 812716 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[1 (1594986088651292672)]} 0 1
[junit4] 2> 812717 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[2 (1594986088653389824)]} 0 0
[junit4] 2> 812719 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[2 (1594986088654438400)]} 0 0
[junit4] 2> 812720 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[3 (1594986088656535552)]} 0 0
[junit4] 2> 812721 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[3 (1594986088657584128)]} 0 0
[junit4] 2> 812722 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[4 (1594986088658632704)]} 0 0
[junit4] 2> 812723 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[4 (1594986088659681280)]} 0 0
[junit4] 2> 812724 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[5 (1594986088660729856)]} 0 0
[junit4] 2> 812725 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[5 (1594986088661778432)]} 0 0
[junit4] 2> 812726 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[6 (1594986088662827008)]} 0 0
[junit4] 2> 812728 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[6 (1594986088663875584)]} 0 0
[junit4] 2> 812729 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[7 (1594986088664924160)]} 0 0
[junit4] 2> 812730 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[7 (1594986088665972736)]} 0 0
[junit4] 2> 812731 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[8 (1594986088667021312)]} 0 0
[junit4] 2> 812732 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[8 (1594986088668069888)]} 0 0
[junit4] 2> 812733 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[9 (1594986088670167040)]} 0 0
[junit4] 2> 812734 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[9 (1594986088671215616)]} 0 0
[junit4] 2> 812735 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1594986088672264192,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 812735 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@33c87267 commitCommandVersion:1594986088672264192
[junit4] 2> 812741 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@63ae7b47[collection1] main]
[junit4] 2> 812742 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 812744 INFO (searcherExecutor-2997-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@63ae7b47[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.4.0):c9)))}
[junit4] 2> 812744 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 9
[junit4] 2> 812745 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1594986088682749952,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 812745 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@78d6a74d commitCommandVersion:1594986088682749952
[junit4] 2> 812774 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@553777ee[collection1] main]
[junit4] 2> 812775 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 812776 INFO (searcherExecutor-3008-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@553777ee[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.4.0):c9)))}
[junit4] 2> 812776 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 31
[junit4] 2> 812779 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[10 (1594986088716304384)]} 0 1
[junit4] 2> 812781 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[10 (1594986088719450112)]} 0 1
[junit4] 2> 812783 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[11 (1594986088721547264)]} 0 1
[junit4] 2> 812784 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[11 (1594986088722595840)]} 0 0
[junit4] 2> 812785 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[12 (1594986088724692992)]} 0 0
[junit4] 2> 812786 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[12 (1594986088725741568)]} 0 0
[junit4] 2> 812787 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[13 (1594986088726790144)]} 0 0
[junit4] 2> 812788 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[13 (1594986088727838720)]} 0 0
[junit4] 2> 812789 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[1001 (1594986088728887296)]} 0 0
[junit4] 2> 812790 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[1001 (1594986088729935872)]} 0 0
[junit4] 2> 812791 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[14 (1594986088730984448)]} 0 0
[junit4] 2> 812792 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[14 (1594986088732033024)]} 0 0
[junit4] 2> 812793 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[15 (1594986088732033024)]} 0 0
[junit4] 2> 812793 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[15 (1594986088733081600)]} 0 0
[junit4] 2> 812794 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[16 (1594986088734130176)]} 0 0
[junit4] 2> 812795 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[16 (1594986088735178752)]} 0 0
[junit4] 2> 812796 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[17 (1594986088735178752)]} 0 0
[junit4] 2> 812796 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[17 (1594986088736227328)]} 0 0
[junit4] 2> 812797 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[100 (1594986088737275904)]} 0 0
[junit4] 2> 812798 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[100 (1594986088738324480)]} 0 0
[junit4] 2> 812799 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[101 (1594986088739373056)]} 0 0
[junit4] 2> 812800 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[101 (1594986088739373056)]} 0 0
[junit4] 2> 812800 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[102 (1594986088740421632)]} 0 0
[junit4] 2> 812801 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[102 (1594986088741470208)]} 0 0
[junit4] 2> 812802 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[103 (1594986088742518784)]} 0 0
[junit4] 2> 812803 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[103 (1594986088742518784)]} 0 0
[junit4] 2> 812803 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[104 (1594986088743567360)]} 0 0
[junit4] 2> 812804 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[104 (1594986088744615936)]} 0 0
[junit4] 2> 812805 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[105 (1594986088745664512)]} 0 0
[junit4] 2> 812806 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[105 (1594986088746713088)]} 0 0
[junit4] 2> 812807 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[106 (1594986088747761664)]} 0 0
[junit4] 2> 812807 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[106 (1594986088747761664)]} 0 0
[junit4] 2> 812807 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[107 (1594986088747761665)]} 0 0
[junit4] 2> 812811 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[107 (1594986088747761665)]} 0 4
[junit4] 2> 812812 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[108 (1594986088753004544)]} 0 0
[junit4] 2> 812812 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[108 (1594986088753004544)]} 0 0
[junit4] 2> 812813 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[109 (1594986088754053120)]} 0 0
[junit4] 2> 812814 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[109 (1594986088755101696)]} 0 0
[junit4] 2> 812814 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[110 (1594986088755101696)]} 0 0
[junit4] 2> 812815 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[110 (1594986088756150272)]} 0 0
[junit4] 2> 812816 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[111 (1594986088757198848)]} 0 0
[junit4] 2> 812817 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[111 (1594986088757198848)]} 0 0
[junit4] 2> 812817 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[112 (1594986088758247424)]} 0 0
[junit4] 2> 812818 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[112 (1594986088759296000)]} 0 0
[junit4] 2> 812819 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[113 (1594986088759296000)]} 0 0
[junit4] 2> 812819 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[113 (1594986088760344576)]} 0 0
[junit4] 2> 812820 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[114 (1594986088761393152)]} 0 0
[junit4] 2> 812821 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[114 (1594986088762441728)]} 0 0
[junit4] 2> 812822 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[115 (1594986088762441728)]} 0 0
[junit4] 2> 812822 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[115 (1594986088763490304)]} 0 0
[junit4] 2> 812823 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[116 (1594986088764538880)]} 0 0
[junit4] 2> 812824 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[116 (1594986088765587456)]} 0 0
[junit4] 2> 812825 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[117 (1594986088765587456)]} 0 0
[junit4] 2> 812825 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[117 (1594986088766636032)]} 0 0
[junit4] 2> 812826 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[118 (1594986088767684608)]} 0 0
[junit4] 2> 812826 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[118 (1594986088767684608)]} 0 0
[junit4] 2> 812827 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[119 (1594986088768733184)]} 0 0
[junit4] 2> 812828 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[119 (1594986088769781760)]} 0 0
[junit4] 2> 812828 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[120 (1594986088769781760)]} 0 0
[junit4] 2> 812829 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[120 (1594986088770830336)]} 0 0
[junit4] 2> 812830 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[121 (1594986088770830336)]} 0 0
[junit4] 2> 812830 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[121 (1594986088771878912)]} 0 0
[junit4] 2> 812831 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[122 (1594986088772927488)]} 0 0
[junit4] 2> 812832 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[122 (1594986088772927488)]} 0 0
[junit4] 2> 812833 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[123 (1594986088775024640)]} 0 0
[junit4] 2> 812834 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[123 (1594986088776073216)]} 0 0
[junit4] 2> 812835 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[124 (1594986088777121792)]} 0 0
[junit4] 2> 812836 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[124 (1594986088778170368)]} 0 0
[junit4] 2> 812837 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[125 (1594986088779218944)]} 0 0
[junit4] 2> 812838 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[125 (1594986088780267520)]} 0 0
[junit4] 2> 812839 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[126 (1594986088781316096)]} 0 0
[junit4] 2> 812840 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[126 (1594986088782364672)]} 0 0
[junit4] 2> 812841 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[127 (1594986088783413248)]} 0 0
[junit4] 2> 812842 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[127 (1594986088784461824)]} 0 0
[junit4] 2> 812843 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[128 (1594986088785510400)]} 0 0
[junit4] 2> 812844 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[128 (1594986088786558976)]} 0 0
[junit4] 2> 812845 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[129 (1594986088787607552)]} 0 0
[junit4] 2> 812846 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[129 (1594986088788656128)]} 0 0
[junit4] 2> 812847 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[130 (1594986088789704704)]} 0 0
[junit4] 2> 812848 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[130 (1594986088790753280)]} 0 0
[junit4] 2> 812849 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[131 (1594986088791801856)]} 0 0
[junit4] 2> 812850 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[131 (1594986088792850432)]} 0 0
[junit4] 2> 812851 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[132 (1594986088792850432)]} 0 0
[junit4] 2> 812852 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[132 (1594986088793899008)]} 0 0
[junit4] 2> 812853 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[133 (1594986088794947584)]} 0 0
[junit4] 2> 812854 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[133 (1594986088795996160)]} 0 0
[junit4] 2> 812854 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[134 (1594986088797044736)]} 0 0
[junit4] 2> 812862 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[134 (1594986088805433344)]} 0 0
[junit4] 2> 812863 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[135 (1594986088806481920)]} 0 0
[junit4] 2> 812864 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[135 (1594986088807530496)]} 0 0
[junit4] 2> 812865 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[136 (1594986088808579072)]} 0 0
[junit4] 2> 812866 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[136 (1594986088809627648)]} 0 0
[junit4] 2> 812868 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[137 (1594986088810676224)]} 0 0
[junit4] 2> 812869 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[137 (1594986088811724800)]} 0 0
[junit4] 2> 812869 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[138 (1594986088812773376)]} 0 0
[junit4] 2> 812870 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[138 (1594986088813821952)]} 0 0
[junit4] 2> 812871 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[139 (1594986088814870528)]} 0 0
[junit4] 2> 812872 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[139 (1594986088815919104)]} 0 0
[junit4] 2> 812873 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[140 (1594986088816967680)]} 0 0
[junit4] 2> 812874 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[140 (1594986088818016256)]} 0 0
[junit4] 2> 812875 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[141 (1594986088819064832)]} 0 0
[junit4] 2> 812877 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[141 (1594986088820113408)]} 0 0
[junit4] 2> 812878 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[142 (1594986088822210560)]} 0 0
[junit4] 2> 812881 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[142 (1594986088823259136)]} 0 2
[junit4] 2> 812885 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[143 (1594986088828502016)]} 0 1
[junit4] 2> 812887 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[143 (1594986088830599168)]} 0 0
[junit4] 2> 812888 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[144 (1594986088832696320)]} 0 0
[junit4] 2> 812890 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[144 (1594986088834793472)]} 0 0
[junit4] 2> 812892 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[145 (1594986088836890624)]} 0 0
[junit4] 2> 812893 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[145 (1594986088837939200)]} 0 0
[junit4] 2> 812894 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[146 (1594986088838987776)]} 0 0
[junit4] 2> 812896 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[146 (1594986088841084928)]} 0 0
[junit4] 2> 812898 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[147 (1594986088842133504)]} 0 0
[junit4] 2> 812898 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[147 (1594986088843182080)]} 0 0
[junit4] 2> 812899 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[148 (1594986088844230656)]} 0 0
[junit4] 2> 812900 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[148 (1594986088844230656)]} 0 0
[junit4] 2> 812900 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[149 (1594986088845279232)]} 0 0
[junit4] 2> 812901 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={wt=javabin&version=2}{add=[149 (1594986088846327808)]} 0 0
[junit4] 2> 812901 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1594986088846327808,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 812901 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@33c87267 commitCommandVersion:1594986088846327808
[junit4] 2> 812909 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@20c8b2d0[collection1] main]
[junit4] 2> 812909 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 812910 INFO (searcherExecutor-2997-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@20c8b2d0[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.4.0):c9) Uninverting(_1(7.4.0):c59)))}
[junit4] 2> 812911 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 9
[junit4] 2> 812911 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1594986088856813568,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 812911 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@78d6a74d commitCommandVersion:1594986088856813568
[junit4] 2> 812918 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@54eb91c6[collection1] main]
[junit4] 2> 812918 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 812920 INFO (searcherExecutor-3008-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@54eb91c6[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.4.0):c9) Uninverting(_1(7.4.0):c59)))}
[junit4] 2> 812920 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/ets path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 9
[junit4] 2> 812922 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching parameter cannot be negative
[junit4] 2> 812922 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*&distrib=false&start=-1&wt=javabin&version=2} status=400 QTime=0
[junit4] 2> 812923 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching parameter cannot be negative
[junit4] 2> 812923 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*&distrib=false&start=0&rows=-1&wt=javabin&version=2} status=400 QTime=0
[junit4] 2> 812924 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_ti1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 812928 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_ti1+desc&shard.url=http://127.0.0.1:41443/ets/collection1&rows=10&version=2&q=*:*&NOW=1521097267982&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 812933 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097267982&ids=100,111,12,13,113,5,149,127,7,108&isShard=true&shard.url=http://127.0.0.1:41443/ets/collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 812938 INFO (qtp1283414720-9163) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=http://127.0.0.1:41443/ets/collection1&sort=n_ti1+desc&wt=javabin&version=2} hits=68 status=0 QTime=13
[junit4] 2> 812943 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_ti1+asc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 812947 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_ti1+asc&shard.url=http://127.0.0.1:41443/ets/collection1|[ff01::083]:33332/ets&rows=10&version=2&q=*:*&NOW=1521097268002&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 812948 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268002&ids=121,1,3,114,147,126,148,6,109,142&isShard=true&shard.url=http://127.0.0.1:41443/ets/collection1|[ff01::083]:33332/ets&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 812955 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=http://127.0.0.1:41443/ets/collection1|[ff01::083]:33332/ets&sort=n_ti1+asc&wt=javabin&version=2} hits=68 status=0 QTime=9
[junit4] 2> 812957 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_f1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 812959 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_f1+desc&shard.url=http://127.0.0.1:41443/ets/collection1|[ff01::114]:33332/ets&rows=10&version=2&q=*:*&NOW=1521097268015&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 812960 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268015&ids=121,101,2,123,102,125,15,116,7,131&isShard=true&shard.url=http://127.0.0.1:41443/ets/collection1|[ff01::114]:33332/ets&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 812968 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=http://127.0.0.1:41443/ets/collection1|[ff01::114]:33332/ets&sort=n_f1+desc&wt=javabin&version=2} hits=68 status=0 QTime=10
[junit4] 2> 812969 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_f1+asc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 812972 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_f1+asc&shard.url=http://127.0.0.1:41443/ets/collection1|[ff01::083]:33332/ets|[ff01::114]:33332/ets|[ff01::213]:33332/ets&rows=10&version=2&q=*:*&NOW=1521097268028&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 812974 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268028&ids=135,136,147,114,104,17,105,107,9,120&isShard=true&shard.url=http://127.0.0.1:41443/ets/collection1|[ff01::083]:33332/ets|[ff01::114]:33332/ets|[ff01::213]:33332/ets&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 812979 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=http://127.0.0.1:41443/ets/collection1|[ff01::083]:33332/ets|[ff01::114]:33332/ets|[ff01::213]:33332/ets&sort=n_f1+asc&wt=javabin&version=2} hits=68 status=0 QTime=8
[junit4] 2> 812980 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_tf1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 812982 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tf1+desc&shard.url=http://127.0.0.1:41443/ets/collection1|[ff01::213]:33332/ets&rows=10&version=2&q=*:*&NOW=1521097268039&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 812986 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268039&ids=111,100,145,14,3,147,137,116,127,1001&isShard=true&shard.url=http://127.0.0.1:41443/ets/collection1|[ff01::213]:33332/ets&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 812993 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=http://127.0.0.1:41443/ets/collection1|[ff01::213]:33332/ets&sort=n_tf1+desc&wt=javabin&version=2} hits=68 status=0 QTime=11
[junit4] 2> 812995 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_tf1+asc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 813007 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tf1+asc&shard.url=[ff01::213]:33332/ets|[ff01::083]:33332/ets|http://127.0.0.1:41443/ets/collection1&rows=10&version=2&q=*:*&NOW=1521097268053&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 813008 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268053&ids=110,101,135,102,15,139,7,128,118,9&isShard=true&shard.url=[ff01::213]:33332/ets|[ff01::083]:33332/ets|http://127.0.0.1:41443/ets/collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 813009 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=[ff01::213]:33332/ets|[ff01::083]:33332/ets|http://127.0.0.1:41443/ets/collection1&sort=n_tf1+asc&wt=javabin&version=2} hits=68 status=0 QTime=13
[junit4] 2> 813010 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_d1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 813012 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_d1+desc&shard.url=http://127.0.0.1:41443/ets/collection1&rows=10&version=2&q=*:*&NOW=1521097268068&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 813013 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268068&ids=12,134,3,14,102,114,5,17,139,108&isShard=true&shard.url=http://127.0.0.1:41443/ets/collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 813013 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=http://127.0.0.1:41443/ets/collection1&sort=n_d1+desc&wt=javabin&version=2} hits=68 status=0 QTime=2
[junit4] 2> 813014 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_d1+asc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 813017 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_d1+asc&shard.url=[ff01::114]:33332/ets|http://127.0.0.1:41443/ets/collection1|[ff01::083]:33332/ets|[ff01::213]:33332/ets&rows=10&version=2&q=*:*&NOW=1521097268072&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 813018 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268072&ids=143,111,147,15,126,138,149,7,8,9&isShard=true&shard.url=[ff01::114]:33332/ets|http://127.0.0.1:41443/ets/collection1|[ff01::083]:33332/ets|[ff01::213]:33332/ets&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 813019 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=[ff01::114]:33332/ets|http://127.0.0.1:41443/ets/collection1|[ff01::083]:33332/ets|[ff01::213]:33332/ets&sort=n_d1+asc&wt=javabin&version=2} hits=68 status=0 QTime=3
[junit4] 2> 813019 INFO (qtp1787773126-9148) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_td1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 813021 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_td1+desc&shard.url=[ff01::083]:33332/ets|[ff01::114]:33332/ets|[ff01::213]:33332/ets|http://127.0.0.1:41443/ets/collection1&rows=10&version=2&q=*:*&NOW=1521097268078&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 813022 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268078&ids=110,145,3,114,125,136,104,126,17,128&isShard=true&shard.url=[ff01::083]:33332/ets|[ff01::114]:33332/ets|[ff01::213]:33332/ets|http://127.0.0.1:41443/ets/collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 813024 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=[ff01::083]:33332/ets|[ff01::114]:33332/ets|[ff01::213]:33332/ets|http://127.0.0.1:41443/ets/collection1&sort=n_td1+desc&wt=javabin&version=2} hits=68 status=0 QTime=3
[junit4] 2> 813025 INFO (qtp1787773126-9146) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_td1+asc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 813027 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_td1+asc&shard.url=http://127.0.0.1:41443/ets/collection1&rows=10&version=2&q=*:*&NOW=1521097268083&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 813028 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268083&ids=132,112,113,124,5,6,138,149,119,109&isShard=true&shard.url=http://127.0.0.1:41443/ets/collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 813029 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=http://127.0.0.1:41443/ets/collection1&sort=n_td1+asc&wt=javabin&version=2} hits=68 status=0 QTime=3
[junit4] 2> 813030 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_l1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 813032 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_l1+desc&shard.url=[ff01::114]:33332/ets|[ff01::083]:33332/ets|http://127.0.0.1:41443/ets/collection1&rows=10&version=2&q=*:*&NOW=1521097268089&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 813034 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268089&ids=110,124,135,114,137,17,1001,8,107,141&isShard=true&shard.url=[ff01::114]:33332/ets|[ff01::083]:33332/ets|http://127.0.0.1:41443/ets/collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 813034 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=[ff01::114]:33332/ets|[ff01::083]:33332/ets|http://127.0.0.1:41443/ets/collection1&sort=n_l1+desc&wt=javabin&version=2} hits=68 status=0 QTime=2
[junit4] 2> 813036 INFO (qtp1787773126-9146) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_l1+asc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 813038 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_l1+asc&shard.url=http://127.0.0.1:41443/ets/collection1&rows=10&version=2&q=*:*&NOW=1521097268094&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 813039 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268094&ids=11,121,111,103,6,138,117,118,129,140&isShard=true&shard.url=http://127.0.0.1:41443/ets/collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 813040 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=http://127.0.0.1:41443/ets/collection1&sort=n_l1+asc&wt=javabin&version=2} hits=68 status=0 QTime=3
[junit4] 2> 813041 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_tl1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 813044 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tl1+desc&shard.url=http://127.0.0.1:41443/ets/collection1&rows=10&version=2&q=*:*&NOW=1521097268100&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 813045 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268100&ids=121,133,111,144,14,113,105,128,141,120&isShard=true&shard.url=http://127.0.0.1:41443/ets/collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 813046 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=http://127.0.0.1:41443/ets/collection1&sort=n_tl1+desc&wt=javabin&version=2} hits=68 status=0 QTime=3
[junit4] 2> 813047 INFO (qtp1787773126-9146) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_tl1+asc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 813049 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tl1+asc&shard.url=http://127.0.0.1:41443/ets/collection1|[ff01::213]:33332/ets|[ff01::083]:33332/ets&rows=10&version=2&q=*:*&NOW=1521097268105&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 813051 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268105&ids=1,145,134,4,147,103,126,138,9,130&isShard=true&shard.url=http://127.0.0.1:41443/ets/collection1|[ff01::213]:33332/ets|[ff01::083]:33332/ets&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 813052 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=http://127.0.0.1:41443/ets/collection1|[ff01::213]:33332/ets|[ff01::083]:33332/ets&sort=n_tl1+asc&wt=javabin&version=2} hits=68 status=0 QTime=3
[junit4] 2> 813053 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_dt1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 813056 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_dt1+desc&shard.url=[ff01::114]:33332/ets|[ff01::083]:33332/ets|http://127.0.0.1:41443/ets/collection1&rows=10&version=2&q=*:*&NOW=1521097268112&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 813058 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268112&ids=13,146,135,148,149,106,118,9,130,142&isShard=true&shard.url=[ff01::114]:33332/ets|[ff01::083]:33332/ets|http://127.0.0.1:41443/ets/collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 813059 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=[ff01::114]:33332/ets|[ff01::083]:33332/ets|http://127.0.0.1:41443/ets/collection1&sort=n_dt1+desc&wt=javabin&version=2} hits=68 status=0 QTime=3
[junit4] 2> 813060 INFO (qtp1787773126-9146) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_dt1+asc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 813062 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_dt1+asc&shard.url=[ff01::213]:33332/ets|http://127.0.0.1:41443/ets/collection1&rows=10&version=2&q=*:*&NOW=1521097268118&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 813063 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268118&ids=121,11,1,112,123,15,147,139,141,131&isShard=true&shard.url=[ff01::213]:33332/ets|http://127.0.0.1:41443/ets/collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 813064 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=[ff01::213]:33332/ets|http://127.0.0.1:41443/ets/collection1&sort=n_dt1+asc&wt=javabin&version=2} hits=68 status=0 QTime=2
[junit4] 2> 813065 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_tdt1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 813066 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tdt1+desc&shard.url=[ff01::083]:33332/ets|[ff01::114]:33332/ets|[ff01::213]:33332/ets|http://127.0.0.1:41443/ets/collection1&rows=10&version=2&q=*:*&NOW=1521097268122&isShard=true&wt=javabin} hits=68 status=0 QTime=0
[junit4] 2> 813067 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268122&ids=143,1,102,103,127,8,107,108,140,131&isShard=true&shard.url=[ff01::083]:33332/ets|[ff01::114]:33332/ets|[ff01::213]:33332/ets|http://127.0.0.1:41443/ets/collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 813068 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=[ff01::083]:33332/ets|[ff01::114]:33332/ets|[ff01::213]:33332/ets|http://127.0.0.1:41443/ets/collection1&sort=n_tdt1+desc&wt=javabin&version=2} hits=68 status=0 QTime=2
[junit4] 2> 813069 INFO (qtp1787773126-9146) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=n_tdt1+asc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 813072 INFO (qtp1283414720-9165) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tdt1+asc&shard.url=http://127.0.0.1:41443/ets/collection1|[ff01::213]:33332/ets&rows=10&version=2&q=*:*&NOW=1521097268127&isShard=true&wt=javabin} hits=68 status=0 QTime=1
[junit4] 2> 813073 INFO (qtp1283414720-9168) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1521097268127&ids=13,145,3,125,136,5,148,117,130,10&isShard=true&shard.url=http://127.0.0.1:41443/ets/collection1|[ff01::213]:33332/ets&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 813074 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&shards=http://127.0.0.1:41443/ets/collection1|[ff01::213]:33332/ets&sort=n_tdt1+asc&wt=javabin&version=2} hits=68 status=0 QTime=3
[junit4] 2> 813076 INFO (qtp1787773126-9150) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={q=*:*&distrib=false&sort=a_i1+desc&wt=javabin&version=2} hits=68 status=0 QTime=0
[junit4] 2> 813077 INFO (qtp1283414720-9166) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/ets path=/select params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=a_i1+desc&shard.url=http://127.0.0.1:41443/ets/collection1&rows=10&version=2&q=*:*&NOW=1521097268134&isShard=true&
[...truncated too long message...]
rMetricManager Closing metric reporters for registry=solr.core.collection1, tag=63000775
[junit4] 2> 841450 INFO (coreCloseExecutor-3054-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@34df5a84: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@50eb233
[junit4] 2> 841460 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1cd5ab6c{/ets,null,UNAVAILABLE}
[junit4] 2> 841461 INFO (TEST-TestDistributedSearch.test-seed#[1100A2614CAEB74A]) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestDistributedSearch -Dtests.method=test -Dtests.seed=1100A2614CAEB74A -Dtests.slow=true -Dtests.locale=es -Dtests.timezone=America/Port-au-Prince -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 30.0s J1 | TestDistributedSearch.test <<<
[junit4] > Throwable #1: java.lang.AssertionError: Expected to find shardAddress in the up shard info: {error=org.apache.solr.client.solrj.SolrServerException: Time allowed to handle this request exceeded,trace=org.apache.solr.client.solrj.SolrServerException: Time allowed to handle this request exceeded
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:460)
[junit4] > at org.apache.solr.handler.component.HttpShardHandlerFactory.makeLoadBalancedRequest(HttpShardHandlerFactory.java:273)
[junit4] > at org.apache.solr.handler.component.HttpShardHandler.lambda$submit$0(HttpShardHandler.java:175)
[junit4] > at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] > at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] > at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
[junit4] > at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] > ,time=4}
[junit4] > at __randomizedtesting.SeedInfo.seed([1100A2614CAEB74A:99549DBBE252DAB2]:0)
[junit4] > at org.apache.solr.TestDistributedSearch.comparePartialResponses(TestDistributedSearch.java:1191)
[junit4] > at org.apache.solr.TestDistributedSearch.queryPartialResults(TestDistributedSearch.java:1132)
[junit4] > at org.apache.solr.TestDistributedSearch.test(TestDistributedSearch.java:992)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsRepeatStatement.callStatement(BaseDistributedSearchTestCase.java:1019)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:968)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.TestDistributedSearch_1100A2614CAEB74A-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {severity=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), foo_sev_enum=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), SubjectTerms_mfacet=PostingsFormat(name=Memory), multiDefault=PostingsFormat(name=Direct), rnd_b=FST50, a_s=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), oddField_s=FST50, lowerfilt1and2=PostingsFormat(name=Direct), a_t=PostingsFormat(name=Direct), foo_b=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), lowerfilt=PostingsFormat(name=Direct), id=FST50, text=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128)))}, docValues:{other_tl1=DocValuesFormat(name=Memory), range_facet_l_dv=DocValuesFormat(name=Asserting), n_l1=DocValuesFormat(name=Lucene70), a_n_tdt=DocValuesFormat(name=Direct), intDefault=DocValuesFormat(name=Memory), n_td1=DocValuesFormat(name=Memory), n_d1=DocValuesFormat(name=Lucene70), range_facet_l=DocValuesFormat(name=Lucene70), n_f1=DocValuesFormat(name=Memory), n_tl1=DocValuesFormat(name=Memory), n_tf1=DocValuesFormat(name=Lucene70), intDvoDefault=DocValuesFormat(name=Asserting), timestamp=DocValuesFormat(name=Lucene70), severity=DocValuesFormat(name=Direct), foo_sev_enum=DocValuesFormat(name=Direct), n_dt1=DocValuesFormat(name=Memory), a_i1=DocValuesFormat(name=Lucene70), b_n_tdt=DocValuesFormat(name=Memory), n_ti1=DocValuesFormat(name=Asserting), _version_=DocValuesFormat(name=Memory), n_tdt1=DocValuesFormat(name=Memory), id_i1=DocValuesFormat(name=Memory), foo_d=DocValuesFormat(name=Asserting), range_facet_i_dv=DocValuesFormat(name=Lucene70), foo_f=DocValuesFormat(name=Direct)}, maxPointsInLeafNode=1622, maxMBSortInHeap=7.245197627528521, sim=RandomSimilarity(queryNorm=false): {}, locale=es, timezone=America/Port-au-Prince
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_162 (64-bit)/cpus=3,threads=1,free=115136672,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestInPlaceUpdatesStandalone, TestStressInPlaceUpdates, TestFreeTextSuggestions, TestStressVersions, StressHdfsTest, DocExpirationUpdateProcessorFactoryTest, TestPHPSerializedResponseWriter, FullSolrCloudDistribCmdsTest, BadCopyFieldTest, BufferStoreTest, OverseerTest, TestCoreAdminApis, TermVectorComponentTest, TestZkAclsWithHadoopAuth, ShardRoutingTest, NoCacheHeaderTest, HdfsCollectionsAPIDistributedZkTest, TestNamedUpdateProcessors, DateRangeFieldTest, AtomicUpdateProcessorFactoryTest, CdcrReplicationDistributedZkTest, TestFieldCacheSort, ReplicationFactorTest, PeerSyncWithIndexFingerprintCachingTest, TestLMDirichletSimilarityFactory, SolrCloudReportersTest, FileBasedSpellCheckerTest, ReplaceNodeNoTargetTest, TestNodeAddedTrigger, PeerSyncTest, DebugComponentTest, TestHdfsUpdateLog, TestUpdate, TestNumericRangeQuery64, IndexSchemaTest, ClassificationUpdateProcessorFactoryTest, TestNonDefinedSimilarityFactory, TestTrackingShardHandlerFactory, HdfsChaosMonkeySafeLeaderTest, ConnectionManagerTest, HighlighterConfigTest, PrimitiveFieldTypeTest, SimplePostToolTest, TestLRUCache, SolrCLIZkUtilsTest, TestSubQueryTransformerCrossCore, TestLegacyFieldCache, FieldAnalysisRequestHandlerTest, TestPointFields, ParsingFieldUpdateProcessorsTest, NotRequiredUniqueKeyTest, SpellCheckCollatorTest, TestDocBasedVersionConstraints, TestBackupRepositoryFactory, DistanceUnitsTest, TestFastWriter, ResponseLogComponentTest, TestLocalFSCloudBackupRestore, TestComplexPhraseLeadingWildcard, TestMacros, ClusterStateTest, HdfsDirectoryFactoryTest, TestReversedWildcardFilterFactory, ZkStateReaderTest, DOMUtilTest, HighlighterMaxOffsetTest, ExplicitHLLTest, DirectoryFactoryTest, OutOfBoxZkACLAndCredentialsProvidersTest, TestLegacyNumericRangeQueryBuilder, ShufflingReplicaListTransformerTest, HdfsBasicDistributedZkTest, TestCollectionsAPIViaSolrCloudCluster, TestFieldCacheVsDocValues, TokenizerChainTest, MetricTriggerTest, TestNestedDocsSort, UUIDFieldTest, TestDistribIDF, TestTrieFacet, TestQueryWrapperFilter, TestGeoJSONResponseWriter, TestDynamicLoading, BadIndexSchemaTest, TestManagedSynonymFilterFactory, ClassificationUpdateProcessorTest, DocumentAnalysisRequestHandlerTest, TestCustomSort, TestDistributedStatsComponentCardinality, TestScoreJoinQPScore, DirectUpdateHandlerTest, RollingRestartTest, PrimUtilsTest, TestReqParamsAPI, DistanceFunctionTest, LargeFieldTest, DocValuesTest, DistributedSuggestComponentTest, DistribDocExpirationUpdateProcessorTest, TestSolrCloudWithSecureImpersonation, ZkShardTermsTest, TestRandomDVFaceting, CloudMLTQParserTest, CollectionReloadTest, TestBlendedInfixSuggestions, SmileWriterTest, TestDFRSimilarityFactory, TestStressRecovery, TestChildDocTransformer, CloudExitableDirectoryReaderTest, RulesTest, TestSizeLimitedDistributedMap, TestAtomicUpdateErrorCases, TestIndexingPerformance, TestSchemaResource, TestSolrIndexConfig, TestConfigReload, TestRawResponseWriter, SolrCmdDistributorTest, TestDocumentBuilder, DistributedQueueTest, TestHalfAndHalfDocValues, TestDistribDocBasedVersion, TestDistributedSearch]
[junit4] Completed [213/783 (1!)] on J1 in 30.06s, 1 test, 1 failure <<< FAILURES!
[...truncated 51578 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/494/consoleText
[repro] Revision: 02425b27316caf389554ebf5fe333915cb420289
[repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseG1GC"
[repro] Repro line: ant test -Dtestcase=TestDistributedSearch -Dtests.method=test -Dtests.seed=1100A2614CAEB74A -Dtests.slow=true -Dtests.locale=es -Dtests.timezone=America/Port-au-Prince -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] TestDistributedSearch
[repro] ant compile-test
[...truncated 3331 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestDistributedSearch" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UseG1GC" -Dtests.seed=1100A2614CAEB74A -Dtests.slow=true -Dtests.locale=es -Dtests.timezone=America/Port-au-Prince -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[...truncated 70 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.TestDistributedSearch
[repro] Exiting with code 0
[...truncated 70 lines...]