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 2017/03/07 23:07:02 UTC
[JENKINS-EA] Lucene-Solr-6.4-Linux (32bit/jdk-9-ea+159) - Build #
152 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.4-Linux/152/
Java: 32bit/jdk-9-ea+159 -client -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingSorting
Error Message:
Should have exactly 4 documents returned expected:<4> but was:<3>
Stack Trace:
java.lang.AssertionError: Should have exactly 4 documents returned expected:<4> but was:<3>
at __randomizedtesting.SeedInfo.seed([8AA110EC2738523F:949918E45B93E8BF]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.DocValuesNotIndexedTest.checkSortOrder(DocValuesNotIndexedTest.java:259)
at org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingSorting(DocValuesNotIndexedTest.java:244)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:547)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:811)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 12310 lines...]
[junit4] Suite: org.apache.solr.cloud.DocValuesNotIndexedTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/init-core-data-001
[junit4] 2> 1619153 INFO (SUITE-DocValuesNotIndexedTest-seed#[8AA110EC2738523F]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 1619158 INFO (SUITE-DocValuesNotIndexedTest-seed#[8AA110EC2738523F]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001
[junit4] 2> 1619159 INFO (SUITE-DocValuesNotIndexedTest-seed#[8AA110EC2738523F]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1619161 INFO (Thread-2420) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1619162 INFO (Thread-2420) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1619261 INFO (SUITE-DocValuesNotIndexedTest-seed#[8AA110EC2738523F]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:45091
[junit4] 2> 1619270 INFO (jetty-launcher-1924-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1619270 INFO (jetty-launcher-1924-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1619271 INFO (jetty-launcher-1924-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1c04fa5{/solr,null,AVAILABLE}
[junit4] 2> 1619271 INFO (jetty-launcher-1924-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@b19017{/solr,null,AVAILABLE}
[junit4] 2> 1619273 INFO (jetty-launcher-1924-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@9c3304{SSL,[ssl, http/1.1]}{127.0.0.1:36322}
[junit4] 2> 1619273 INFO (jetty-launcher-1924-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@555a7c{SSL,[ssl, http/1.1]}{127.0.0.1:33968}
[junit4] 2> 1619273 INFO (jetty-launcher-1924-thread-1) [ ] o.e.j.s.Server Started @1621182ms
[junit4] 2> 1619273 INFO (jetty-launcher-1924-thread-2) [ ] o.e.j.s.Server Started @1621182ms
[junit4] 2> 1619274 INFO (jetty-launcher-1924-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36322}
[junit4] 2> 1619274 INFO (jetty-launcher-1924-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=33968}
[junit4] 2> 1619274 ERROR (jetty-launcher-1924-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1619274 ERROR (jetty-launcher-1924-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1619274 INFO (jetty-launcher-1924-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.4.3
[junit4] 2> 1619274 INFO (jetty-launcher-1924-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.4.3
[junit4] 2> 1619274 INFO (jetty-launcher-1924-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1619274 INFO (jetty-launcher-1924-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1619274 INFO (jetty-launcher-1924-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1619274 INFO (jetty-launcher-1924-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1619274 INFO (jetty-launcher-1924-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-07T22:47:12.276697Z
[junit4] 2> 1619274 INFO (jetty-launcher-1924-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-07T22:47:12.276736Z
[junit4] 2> 1619276 INFO (jetty-launcher-1924-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1619276 INFO (jetty-launcher-1924-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1619283 INFO (jetty-launcher-1924-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1619284 INFO (jetty-launcher-1924-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1619286 INFO (jetty-launcher-1924-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45091/solr
[junit4] 2> 1619288 INFO (jetty-launcher-1924-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45091/solr
[junit4] 2> 1619297 INFO (jetty-launcher-1924-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:36322_solr
[junit4] 2> 1619298 INFO (jetty-launcher-1924-thread-2) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33968_solr
[junit4] 2> 1619299 INFO (zkCallback-1933-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1619299 INFO (zkCallback-1935-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1619299 INFO (jetty-launcher-1924-thread-1) [ ] o.a.s.c.Overseer Overseer (id=97578308873027590-127.0.0.1:36322_solr-n_0000000000) starting
[junit4] 2> 1619306 INFO (jetty-launcher-1924-thread-1) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36322_solr
[junit4] 2> 1619306 INFO (zkCallback-1933-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1619306 INFO (zkCallback-1935-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1619343 INFO (jetty-launcher-1924-thread-2) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node2/.
[junit4] 2> 1619397 INFO (jetty-launcher-1924-thread-1) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node1/.
[junit4] 2> 1620538 INFO (SUITE-DocValuesNotIndexedTest-seed#[8AA110EC2738523F]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1620538 INFO (SUITE-DocValuesNotIndexedTest-seed#[8AA110EC2738523F]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:45091/solr ready
[junit4] 2> 1620612 INFO (qtp10470628-10419) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf1&maxShardsPerNode=2&name=dv_coll&action=CREATE&numShards=4&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1620614 INFO (OverseerThreadFactory-5712-thread-1) [ ] o.a.s.c.CreateCollectionCmd Create collection dv_coll
[junit4] 2> 1620722 INFO (qtp10470628-10421) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&name=dv_coll_shard3_replica1&action=CREATE&numShards=4&collection=dv_coll&shard=shard3&wt=javabin&version=2
[junit4] 2> 1620722 INFO (qtp10470628-10431) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&name=dv_coll_shard1_replica1&action=CREATE&numShards=4&collection=dv_coll&shard=shard1&wt=javabin&version=2
[junit4] 2> 1620783 INFO (qtp27823741-10434) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&name=dv_coll_shard4_replica1&action=CREATE&numShards=4&collection=dv_coll&shard=shard4&wt=javabin&version=2
[junit4] 2> 1620800 INFO (qtp27823741-10422) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&name=dv_coll_shard2_replica1&action=CREATE&numShards=4&collection=dv_coll&shard=shard2&wt=javabin&version=2
[junit4] 2> 1620903 INFO (zkCallback-1935-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1620903 INFO (zkCallback-1933-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1621730 INFO (qtp10470628-10431) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.3
[junit4] 2> 1621731 INFO (qtp10470628-10421) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.3
[junit4] 2> 1621737 INFO (qtp10470628-10421) [ ] o.a.s.s.IndexSchema [dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 1621737 INFO (qtp10470628-10431) [ ] o.a.s.s.IndexSchema [dv_coll_shard1_replica1] Schema name=minimal
[junit4] 2> 1621740 INFO (qtp10470628-10421) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1621740 INFO (qtp10470628-10431) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1621740 INFO (qtp10470628-10421) [ ] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard3_replica1' using configuration from collection dv_coll
[junit4] 2> 1621740 INFO (qtp10470628-10431) [ ] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard1_replica1' using configuration from collection dv_coll
[junit4] 2> 1621741 INFO (qtp10470628-10421) [ ] o.a.s.c.SolrCore [[dv_coll_shard3_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node1/dv_coll_shard3_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node1/./dv_coll_shard3_replica1/data/]
[junit4] 2> 1621741 INFO (qtp10470628-10431) [ ] o.a.s.c.SolrCore [[dv_coll_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node1/dv_coll_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node1/./dv_coll_shard1_replica1/data/]
[junit4] 2> 1621755 INFO (qtp10470628-10431) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1621755 INFO (qtp10470628-10421) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1621756 INFO (qtp10470628-10431) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1621756 INFO (qtp10470628-10421) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1621766 INFO (qtp10470628-10431) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1621766 INFO (qtp10470628-10431) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1621766 INFO (qtp10470628-10421) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1621766 INFO (qtp10470628-10421) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1621766 INFO (qtp10470628-10431) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@151c89a[dv_coll_shard1_replica1] main]
[junit4] 2> 1621766 INFO (qtp10470628-10421) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@d5a096[dv_coll_shard3_replica1] main]
[junit4] 2> 1621767 INFO (qtp10470628-10431) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1621767 INFO (qtp10470628-10421) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1621767 INFO (qtp10470628-10431) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1621767 INFO (qtp10470628-10421) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1621767 INFO (qtp10470628-10431) [ ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 1621767 INFO (qtp10470628-10421) [ ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 1621767 INFO (qtp10470628-10431) [ ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1621767 INFO (qtp10470628-10421) [ ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1621767 INFO (qtp10470628-10431) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1621767 INFO (qtp10470628-10421) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1621767 INFO (searcherExecutor-5718-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard1_replica1] Registered new searcher Searcher@151c89a[dv_coll_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1621768 INFO (searcherExecutor-5717-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@d5a096[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1621768 INFO (qtp10470628-10431) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561252944695787520
[junit4] 2> 1621768 INFO (qtp10470628-10421) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561252944695787520
[junit4] 2> 1621772 INFO (qtp10470628-10421) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1621772 INFO (qtp10470628-10431) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1621772 INFO (qtp10470628-10421) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1621772 INFO (qtp10470628-10431) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1621772 INFO (qtp10470628-10421) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:36322/solr/dv_coll_shard3_replica1/
[junit4] 2> 1621772 INFO (qtp10470628-10431) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/
[junit4] 2> 1621772 INFO (qtp10470628-10421) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1621772 INFO (qtp10470628-10431) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1621772 INFO (qtp10470628-10421) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:36322/solr/dv_coll_shard3_replica1/ has no replicas
[junit4] 2> 1621772 INFO (qtp10470628-10431) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/ has no replicas
[junit4] 2> 1621774 INFO (qtp10470628-10421) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:36322/solr/dv_coll_shard3_replica1/ shard3
[junit4] 2> 1621774 INFO (qtp10470628-10431) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/ shard1
[junit4] 2> 1621790 INFO (qtp27823741-10434) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.3
[junit4] 2> 1621794 INFO (qtp27823741-10434) [ ] o.a.s.s.IndexSchema [dv_coll_shard4_replica1] Schema name=minimal
[junit4] 2> 1621795 INFO (qtp27823741-10434) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1621796 INFO (qtp27823741-10434) [ ] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard4_replica1' using configuration from collection dv_coll
[junit4] 2> 1621796 INFO (qtp27823741-10434) [ ] o.a.s.c.SolrCore [[dv_coll_shard4_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node2/dv_coll_shard4_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node2/./dv_coll_shard4_replica1/data/]
[junit4] 2> 1621805 INFO (qtp27823741-10422) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.3
[junit4] 2> 1621806 INFO (qtp27823741-10434) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1621806 INFO (qtp27823741-10434) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1621809 INFO (qtp27823741-10422) [ ] o.a.s.s.IndexSchema [dv_coll_shard2_replica1] Schema name=minimal
[junit4] 2> 1621811 INFO (qtp27823741-10422) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1621811 INFO (qtp27823741-10422) [ ] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard2_replica1' using configuration from collection dv_coll
[junit4] 2> 1621811 INFO (qtp27823741-10422) [ ] o.a.s.c.SolrCore [[dv_coll_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node2/dv_coll_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node2/./dv_coll_shard2_replica1/data/]
[junit4] 2> 1621812 INFO (qtp27823741-10434) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1621812 INFO (qtp27823741-10434) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1621812 INFO (qtp27823741-10434) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1170427[dv_coll_shard4_replica1] main]
[junit4] 2> 1621812 INFO (qtp27823741-10434) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1621813 INFO (qtp27823741-10434) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1621813 INFO (qtp27823741-10434) [ ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 1621813 INFO (qtp27823741-10434) [ ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1621813 INFO (qtp27823741-10434) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1621813 INFO (searcherExecutor-5727-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard4_replica1] Registered new searcher Searcher@1170427[dv_coll_shard4_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1621813 INFO (qtp27823741-10434) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561252944742973440
[junit4] 2> 1621817 INFO (qtp27823741-10434) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1621817 INFO (qtp27823741-10434) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1621817 INFO (qtp27823741-10434) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:33968/solr/dv_coll_shard4_replica1/
[junit4] 2> 1621817 INFO (qtp27823741-10434) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1621817 INFO (qtp27823741-10434) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:33968/solr/dv_coll_shard4_replica1/ has no replicas
[junit4] 2> 1621818 INFO (qtp27823741-10434) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:33968/solr/dv_coll_shard4_replica1/ shard4
[junit4] 2> 1621821 INFO (qtp27823741-10422) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1621821 INFO (qtp27823741-10422) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1621827 INFO (qtp27823741-10422) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1621827 INFO (qtp27823741-10422) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1621827 INFO (qtp27823741-10422) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@26b1cc[dv_coll_shard2_replica1] main]
[junit4] 2> 1621827 INFO (qtp27823741-10422) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1621828 INFO (qtp27823741-10422) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1621828 INFO (qtp27823741-10422) [ ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 1621828 INFO (qtp27823741-10422) [ ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1621828 INFO (qtp27823741-10422) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1621828 INFO (searcherExecutor-5730-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard2_replica1] Registered new searcher Searcher@26b1cc[dv_coll_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1621828 INFO (qtp27823741-10422) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561252944758702080
[junit4] 2> 1621831 INFO (qtp27823741-10422) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1621831 INFO (qtp27823741-10422) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1621831 INFO (qtp27823741-10422) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:33968/solr/dv_coll_shard2_replica1/
[junit4] 2> 1621831 INFO (qtp27823741-10422) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1621831 INFO (qtp27823741-10422) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:33968/solr/dv_coll_shard2_replica1/ has no replicas
[junit4] 2> 1621833 INFO (qtp27823741-10422) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:33968/solr/dv_coll_shard2_replica1/ shard2
[junit4] 2> 1621934 INFO (zkCallback-1935-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1621934 INFO (zkCallback-1933-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1621969 INFO (qtp27823741-10434) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1621972 INFO (qtp27823741-10434) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&name=dv_coll_shard4_replica1&action=CREATE&numShards=4&collection=dv_coll&shard=shard4&wt=javabin&version=2} status=0 QTime=1188
[junit4] 2> 1621975 INFO (qtp10470628-10421) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1621975 INFO (qtp10470628-10431) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1621978 INFO (qtp10470628-10421) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&name=dv_coll_shard3_replica1&action=CREATE&numShards=4&collection=dv_coll&shard=shard3&wt=javabin&version=2} status=0 QTime=1256
[junit4] 2> 1621978 INFO (qtp10470628-10431) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&name=dv_coll_shard1_replica1&action=CREATE&numShards=4&collection=dv_coll&shard=shard1&wt=javabin&version=2} status=0 QTime=1256
[junit4] 2> 1621983 INFO (qtp27823741-10422) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1621986 INFO (qtp27823741-10422) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&name=dv_coll_shard2_replica1&action=CREATE&numShards=4&collection=dv_coll&shard=shard2&wt=javabin&version=2} status=0 QTime=1186
[junit4] 2> 1621988 INFO (qtp10470628-10419) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 1622085 INFO (zkCallback-1935-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1622085 INFO (zkCallback-1933-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1622615 INFO (OverseerCollectionConfigSetProcessor-97578308873027590-127.0.0.1:36322_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 1622988 INFO (qtp10470628-10419) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf1&maxShardsPerNode=2&name=dv_coll&action=CREATE&numShards=4&wt=javabin&version=2} status=0 QTime=2375
[junit4] 2> 1622998 INFO (qtp10470628-10429) [ ] o.a.s.s.SchemaManager managed schema loaded . version : 0
[junit4] 2> 1623000 INFO (qtp10470628-10429) [ ] o.a.s.s.IndexSchema [dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 1623001 INFO (qtp10470628-10429) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1623011 INFO (qtp10470628-10429) [ ] o.a.s.c.ZkController Persisted config data to node /configs/conf1/managed-schema
[junit4] 2> 1623011 INFO (zkCallback-1933-thread-1) [ ] o.a.s.s.ZkIndexSchemaReader A schema change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/configs/conf1/managed-schema, has occurred - updating schema from ZooKeeper ...
[junit4] 2> 1623011 INFO (zkCallback-1935-thread-1) [ ] o.a.s.s.ZkIndexSchemaReader A schema change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/configs/conf1/managed-schema, has occurred - updating schema from ZooKeeper ...
[junit4] 2> 1623011 INFO (zkCallback-1935-thread-2) [ ] o.a.s.s.ZkIndexSchemaReader A schema change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/configs/conf1/managed-schema, has occurred - updating schema from ZooKeeper ...
[junit4] 2> 1623011 INFO (zkCallback-1933-thread-1) [ ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 1 from ZooKeeper
[junit4] 2> 1623011 INFO (zkCallback-1935-thread-2) [ ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 1 from ZooKeeper
[junit4] 2> 1623013 INFO (zkCallback-1935-thread-2) [ ] o.a.s.s.IndexSchema [dv_coll_shard1_replica1] Schema name=minimal
[junit4] 2> 1623014 INFO (zkCallback-1933-thread-1) [ ] o.a.s.s.IndexSchema [dv_coll_shard2_replica1] Schema name=minimal
[junit4] 2> 1623018 INFO (zkCallback-1935-thread-2) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1623018 INFO (zkCallback-1933-thread-2) [ ] o.a.s.s.ZkIndexSchemaReader A schema change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/configs/conf1/managed-schema, has occurred - updating schema from ZooKeeper ...
[junit4] 2> 1623019 INFO (zkCallback-1935-thread-2) [ ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 7 ms
[junit4] 2> 1623019 INFO (Thread-2441) [ ] o.a.s.c.SolrCore config update listener called for core dv_coll_shard4_replica1
[junit4] 2> 1623021 INFO (zkCallback-1933-thread-2) [ ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 1 from ZooKeeper
[junit4] 2> 1623021 INFO (zkCallback-1933-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1623022 INFO (zkCallback-1933-thread-1) [ ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 10 ms
[junit4] 2> 1623023 INFO (Thread-2441) [ ] o.a.s.c.SolrCore core reload dv_coll_shard4_replica1
[junit4] 2> 1623023 INFO (zkCallback-1933-thread-2) [ ] o.a.s.s.IndexSchema [dv_coll_shard4_replica1] Schema name=minimal
[junit4] 2> 1623027 INFO (qtp10470628-10429) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.3
[junit4] 2> 1623028 INFO (zkCallback-1933-thread-2) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1623028 INFO (zkCallback-1933-thread-2) [ ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 6 ms
[junit4] 2> 1623048 INFO (Thread-2442) [ ] o.a.s.c.SolrCore config update listener called for core dv_coll_shard1_replica1
[junit4] 2> 1623049 INFO (Thread-2442) [ ] o.a.s.c.SolrCore config update listener called for core dv_coll_shard3_replica1
[junit4] 2> 1623050 INFO (Thread-2442) [ ] o.a.s.c.SolrCore core reload dv_coll_shard3_replica1
[junit4] 2> 1623058 INFO (Thread-2441) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.3
[junit4] 2> 1623065 INFO (qtp10470628-10429) [ ] o.a.s.s.IndexSchema [dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 1623072 INFO (Thread-2441) [ ] o.a.s.s.IndexSchema [dv_coll_shard4_replica1] Schema name=minimal
[junit4] 2> 1623074 INFO (qtp10470628-10429) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1623075 INFO (qtp10470628-10429) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'dv_coll_shard3_replica1' using configuration from collection dv_coll
[junit4] 2> 1623077 INFO (qtp10470628-10429) [ ] o.a.s.c.SolrCore [[dv_coll_shard3_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node1/dv_coll_shard3_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node1/./dv_coll_shard3_replica1/data/]
[junit4] 2> 1623107 INFO (Thread-2441) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1623108 INFO (Thread-2441) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'dv_coll_shard4_replica1' using configuration from collection dv_coll
[junit4] 2> 1623109 INFO (Thread-2441) [ ] o.a.s.c.SolrCore [[dv_coll_shard4_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node2/dv_coll_shard4_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node2/./dv_coll_shard4_replica1/data/]
[junit4] 2> 1623116 INFO (Thread-2441) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1623116 INFO (Thread-2441) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1623116 INFO (Thread-2441) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@ccb748[dv_coll_shard4_replica1] main]
[junit4] 2> 1623117 INFO (Thread-2441) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1623117 INFO (Thread-2441) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1623118 INFO (Thread-2441) [ ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 1623118 INFO (Thread-2441) [ ] o.a.s.s.ZkIndexSchemaReader Current schema version 1 is already the latest
[junit4] 2> 1623118 INFO (Thread-2441) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1623118 INFO (qtp10470628-10429) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1623118 INFO (qtp10470628-10429) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1623118 INFO (searcherExecutor-5738-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard4_replica1] Registered new searcher Searcher@ccb748[dv_coll_shard4_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1623118 INFO (qtp10470628-10429) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@ad068f[dv_coll_shard3_replica1] main]
[junit4] 2> 1623118 INFO (Thread-2441) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561252946111365120
[junit4] 2> 1623119 INFO (qtp10470628-10429) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1623119 INFO (qtp10470628-10429) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1623119 INFO (qtp10470628-10429) [ ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 1623120 INFO (qtp10470628-10429) [ ] o.a.s.s.ZkIndexSchemaReader Current schema version 1 is already the latest
[junit4] 2> 1623120 INFO (qtp10470628-10429) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1623120 INFO (searcherExecutor-5737-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@ad068f[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1623120 INFO (qtp10470628-10429) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561252946113462272
[junit4] 2> 1623121 INFO (Thread-2441) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1623121 INFO (Thread-2441) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@19da1e4[dv_coll_shard4_replica1] main]
[junit4] 2> 1623122 INFO (Thread-2441) [ ] o.a.s.c.SolrCore [dv_coll_shard4_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@14a2955
[junit4] 2> 1623122 INFO (searcherExecutor-5738-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard4_replica1] Registered new searcher Searcher@19da1e4[dv_coll_shard4_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1623122 INFO (Thread-2441) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.dv_coll.shard4.replica1
[junit4] 2> 1623122 INFO (Thread-2441) [ ] o.a.s.c.SolrCore config update listener called for core dv_coll_shard2_replica1
[junit4] 2> 1623123 INFO (qtp10470628-10429) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1623123 INFO (qtp10470628-10429) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2149ad[dv_coll_shard3_replica1] main]
[junit4] 2> 1623123 INFO (searcherExecutor-5737-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@2149ad[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1623124 INFO (zkCallback-1935-thread-1) [ ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 1 from ZooKeeper
[junit4] 2> 1623124 INFO (qtp10470628-10429) [ ] o.a.s.s.ManagedIndexSchema Waiting up to 599 secs for 3 replicas to apply schema update version 1 for collection dv_coll
[junit4] 2> 1623126 INFO (zkCallback-1935-thread-1) [ ] o.a.s.s.IndexSchema [dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 1623133 INFO (Thread-2442) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.3
[junit4] 2> 1623133 INFO (zkCallback-1935-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1623133 INFO (zkCallback-1935-thread-1) [ ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 9 ms
[junit4] 2> 1623138 INFO (qtp27823741-10430) [ ] o.a.s.c.S.Request [dv_coll_shard2_replica1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1623139 INFO (qtp10470628-10425) [ ] o.a.s.c.S.Request [dv_coll_shard1_replica1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1623139 INFO (qtp27823741-10424) [ ] o.a.s.c.S.Request [dv_coll_shard4_replica1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1623139 INFO (qtp10470628-10429) [ ] o.a.s.s.ManagedIndexSchema Took 15.0ms for 3 replicas to apply schema update version 1 for collection dv_coll
[junit4] 2> 1623139 INFO (qtp10470628-10429) [ ] o.a.s.c.S.Request [dv_coll_shard3_replica1] webapp=/solr path=/schema params={wt=javabin&version=2} status=0 QTime=143
[junit4] 2> 1623139 INFO (qtp10470628-10429) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@eaf5d5
[junit4] 2> 1623140 INFO (qtp10470628-10429) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.dv_coll.shard3.replica1
[junit4] 2> 1623152 INFO (Thread-2442) [ ] o.a.s.s.IndexSchema [dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 1623155 INFO (TEST-DocValuesNotIndexedTest.testGroupingSorting-seed#[8AA110EC2738523F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testGroupingSorting
[junit4] 2> 1623161 INFO (Thread-2442) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1623162 INFO (Thread-2442) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'dv_coll_shard3_replica1' using configuration from collection dv_coll
[junit4] 2> 1623163 INFO (Thread-2442) [ ] o.a.s.c.SolrCore [[dv_coll_shard3_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node1/dv_coll_shard3_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001/tempDir-001/node1/./dv_coll_shard3_replica1/data/]
[junit4] 2> 1623163 INFO (qtp10470628-10425) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1561252946156453888)} 0 2
[junit4] 2> 1623165 INFO (qtp27823741-10426) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1561252946157502464)} 0 2
[junit4] 2> 1623169 INFO (qtp27823741-10422) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard4_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1561252946161696768)} 0 3
[junit4] 2> 1623170 INFO (qtp10470628-10433) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1561252946154356736)} 0 13
[junit4] 2> 1623173 INFO (qtp10470628-10419) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623173 INFO (qtp10470628-10419) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1623174 INFO (qtp27823741-10420) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623174 INFO (qtp27823741-10420) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1623175 INFO (qtp27823741-10420) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1199d28[dv_coll_shard2_replica1] main]
[junit4] 2> 1623176 INFO (qtp10470628-10419) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623176 INFO (qtp10470628-10419) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 2
[junit4] 2> 1623176 INFO (qtp27823741-10420) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623176 INFO (searcherExecutor-5730-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard2_replica1] Registered new searcher Searcher@1199d28[dv_coll_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1623176 INFO (qtp27823741-10434) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623176 INFO (qtp10470628-10423) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623176 INFO (qtp27823741-10434) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1623176 INFO (qtp10470628-10423) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1623176 INFO (qtp27823741-10420) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 2
[junit4] 2> 1623176 INFO (qtp27823741-10434) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623176 INFO (qtp10470628-10423) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@cd7699[dv_coll_shard1_replica1] main]
[junit4] 2> 1623177 INFO (qtp27823741-10434) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard4_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0
[junit4] 2> 1623177 INFO (searcherExecutor-5718-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard1_replica1] Registered new searcher Searcher@cd7699[dv_coll_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1623177 INFO (qtp10470628-10423) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623177 INFO (qtp10470628-10423) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1
[junit4] 2> 1623177 INFO (qtp10470628-10421) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr path=/update params={_stateVer_=dv_coll:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 5
[junit4] 2> 1623179 INFO (Thread-2442) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1623179 INFO (Thread-2442) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1623179 INFO (Thread-2442) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1a47edb[dv_coll_shard3_replica1] main]
[junit4] 2> 1623180 INFO (Thread-2442) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1623180 INFO (Thread-2442) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1623180 INFO (Thread-2442) [ ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 1623181 INFO (Thread-2442) [ ] o.a.s.s.ZkIndexSchemaReader Current schema version 1 is already the latest
[junit4] 2> 1623181 INFO (Thread-2442) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1623181 INFO (searcherExecutor-5746-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@1a47edb[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1623187 INFO (qtp27823741-10420) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica1] webapp=/solr path=/update params={_stateVer_=dv_coll:3&wt=javabin&version=2}{add=[4 (1561252946180571136)]} 0 2
[junit4] 2> 1623189 INFO (qtp10470628-10429) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr path=/update params={_stateVer_=dv_coll:3&wt=javabin&version=2}{add=[1 (1561252946179522560)]} 0 6
[junit4] 2> 1623196 INFO (Thread-2442) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1623198 INFO (qtp10470628-10421) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr path=/update params={_stateVer_=dv_coll:3&wt=javabin&version=2}{add=[2 (1561252946179522560), 3 (1561252946183716864)]} 0 14
[junit4] 2> 1623203 INFO (Thread-2442) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1d27a5d[dv_coll_shard3_replica1] main]
[junit4] 2> 1623203 INFO (qtp10470628-10425) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623203 INFO (qtp10470628-10425) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@107b847
[junit4] 2> 1623204 INFO (searcherExecutor-5746-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@1d27a5d[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.3):C1)))}
[junit4] 2> 1623204 INFO (qtp27823741-10426) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623204 INFO (qtp10470628-10419) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623204 INFO (qtp27823741-10426) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@baf739
[junit4] 2> 1623204 INFO (qtp27823741-10424) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623204 INFO (qtp27823741-10424) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1623205 INFO (qtp27823741-10424) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623204 INFO (qtp10470628-10419) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1a5b86f
[junit4] 2> 1623205 INFO (qtp27823741-10424) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard4_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0
[junit4] 2> 1623207 INFO (qtp27823741-10426) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@fa0957[dv_coll_shard2_replica1] main]
[junit4] 2> 1623207 INFO (searcherExecutor-5730-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard2_replica1] Registered new searcher Searcher@fa0957[dv_coll_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.3):C1)))}
[junit4] 2> 1623207 INFO (qtp27823741-10426) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623207 INFO (qtp27823741-10426) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 2
[junit4] 2> 1623208 INFO (qtp10470628-10425) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@18a8a3[dv_coll_shard3_replica1] main]
[junit4] 2> 1623208 INFO (qtp10470628-10425) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623208 INFO (searcherExecutor-5737-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@18a8a3[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.3):C1) Uninverting(_1(6.4.3):C1)))}
[junit4] 2> 1623208 INFO (qtp10470628-10425) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 5
[junit4] 2> 1623208 INFO (qtp10470628-10425) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@72ae9d
[junit4] 2> 1623209 INFO (qtp10470628-10419) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@149a634[dv_coll_shard1_replica1] main]
[junit4] 2> 1623209 INFO (qtp10470628-10419) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623209 INFO (searcherExecutor-5718-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard1_replica1] Registered new searcher Searcher@149a634[dv_coll_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.3):C1)))}
[junit4] 2> 1623209 INFO (qtp10470628-10419) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 5
[junit4] 2> 1623210 INFO (qtp10470628-10425) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.dv_coll.shard3.replica1
[junit4] 2> 1623211 INFO (qtp10470628-10433) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr path=/update params={_stateVer_=dv_coll:3&commit=true&wt=javabin&version=2}{commit=} 0 10
[junit4] 2> 1623220 INFO (qtp27823741-10523) [ ] o.a.s.c.S.Request [dv_coll_shard2_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&fl=id&shards.purpose=4&start=0&fsv=true&sort=intGSF+asc,id+asc&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard2_replica1/&rows=100&version=2&q=*:*&NOW=1488926836216&isShard=true&wt=javabin} hits=1 status=0 QTime=0
[junit4] 2> 1623220 INFO (qtp10470628-10433) [ ] o.a.s.c.S.Request [dv_coll_shard1_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&fl=id&shards.purpose=4&start=0&fsv=true&sort=intGSF+asc,id+asc&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&rows=100&version=2&q=*:*&NOW=1488926836216&isShard=true&wt=javabin} hits=1 status=0 QTime=0
[junit4] 2> 1623220 INFO (qtp27823741-10432) [ ] o.a.s.c.S.Request [dv_coll_shard4_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&fl=id&shards.purpose=4&start=0&fsv=true&sort=intGSF+asc,id+asc&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard4_replica1/&rows=100&version=2&q=*:*&NOW=1488926836216&isShard=true&wt=javabin} hits=0 status=0 QTime=1
[junit4] 2> 1623220 INFO (qtp10470628-10419) [ ] o.a.s.c.S.Request [dv_coll_shard3_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&fl=id&shards.purpose=4&start=0&fsv=true&sort=intGSF+asc,id+asc&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard3_replica1/&rows=100&version=2&q=*:*&NOW=1488926836216&isShard=true&wt=javabin} hits=1 status=0 QTime=0
[junit4] 2> 1623223 INFO (qtp27823741-10524) [ ] o.a.s.c.S.Request [dv_coll_shard2_replica1] webapp=/solr path=/select params={q=*:*&df=text&distrib=false&_stateVer_=dv_coll:3&shards.purpose=64&NOW=1488926836216&ids=4&isShard=true&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard2_replica1/&rows=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1623223 INFO (qtp10470628-10431) [ ] o.a.s.c.S.Request [dv_coll_shard1_replica1] webapp=/solr path=/select params={q=*:*&df=text&distrib=false&_stateVer_=dv_coll:3&shards.purpose=64&NOW=1488926836216&ids=1&isShard=true&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&rows=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1623223 INFO (qtp10470628-10425) [ ] o.a.s.c.S.Request [dv_coll_shard3_replica1] webapp=/solr path=/select params={q=*:*&df=text&distrib=false&_stateVer_=dv_coll:3&shards.purpose=64&NOW=1488926836216&ids=2&isShard=true&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard3_replica1/&rows=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1623223 INFO (qtp27823741-10434) [ ] o.a.s.c.S.Request [dv_coll_shard2_replica1] webapp=/solr path=/select params={q=*:*&_stateVer_=dv_coll:3&sort=intGSF+asc,id+asc&rows=100&wt=javabin&version=2} hits=3 status=0 QTime=10
[junit4] 2> 1623224 INFO (TEST-DocValuesNotIndexedTest.testGroupingSorting-seed#[8AA110EC2738523F]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testGroupingSorting
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=DocValuesNotIndexedTest -Dtests.method=testGroupingSorting -Dtests.seed=8AA110EC2738523F -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ce-RU -Dtests.timezone=SystemV/CST6CDT -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 0.09s J2 | DocValuesNotIndexedTest.testGroupingSorting <<<
[junit4] > Throwable #1: java.lang.AssertionError: Should have exactly 4 documents returned expected:<4> but was:<3>
[junit4] > at __randomizedtesting.SeedInfo.seed([8AA110EC2738523F:949918E45B93E8BF]:0)
[junit4] > at org.apache.solr.cloud.DocValuesNotIndexedTest.checkSortOrder(DocValuesNotIndexedTest.java:259)
[junit4] > at org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingSorting(DocValuesNotIndexedTest.java:244)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:547)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 1623242 INFO (TEST-DocValuesNotIndexedTest.testGroupingDVOnly-seed#[8AA110EC2738523F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testGroupingDVOnly
[junit4] 2> 1623267 INFO (qtp10470628-10483) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7b2ce6[dv_coll_shard1_replica1] realtime]
[junit4] 2> 1623267 INFO (qtp10470628-10429) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@250a40[dv_coll_shard3_replica1] realtime]
[junit4] 2> 1623267 INFO (qtp27823741-10422) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@cdb5b3[dv_coll_shard2_replica1] realtime]
[junit4] 2> 1623267 INFO (qtp10470628-10429) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1561252946244534272)} 0 21
[junit4] 2> 1623267 INFO (qtp27823741-10422) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1561252946244534272)} 0 21
[junit4] 2> 1623268 INFO (qtp27823741-10522) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard4_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1561252946265505792)} 0 3
[junit4] 2> 1623268 INFO (qtp10470628-10483) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1561252946243485696)} 0 24
[junit4] 2> 1623272 INFO (qtp10470628-10419) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623272 INFO (qtp27823741-10432) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623272 INFO (qtp10470628-10425) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623272 INFO (qtp27823741-10523) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623272 INFO (qtp10470628-10425) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@107b847
[junit4] 2> 1623272 INFO (qtp27823741-10432) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1623272 INFO (qtp10470628-10419) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1a5b86f
[junit4] 2> 1623272 INFO (qtp27823741-10523) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@baf739
[junit4] 2> 1623272 INFO (qtp27823741-10432) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623273 INFO (qtp27823741-10432) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard4_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1
[junit4] 2> 1623273 INFO (qtp10470628-10419) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1d3d470[dv_coll_shard1_replica1] main]
[junit4] 2> 1623273 INFO (qtp27823741-10523) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@162a0be[dv_coll_shard2_replica1] main]
[junit4] 2> 1623273 INFO (qtp10470628-10425) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@a5d398[dv_coll_shard3_replica1] main]
[junit4] 2> 1623273 INFO (searcherExecutor-5718-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard1_replica1] Registered new searcher Searcher@1d3d470[dv_coll_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1623273 INFO (qtp27823741-10523) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623273 INFO (searcherExecutor-5746-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@a5d398[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1623273 INFO (qtp10470628-10425) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623273 INFO (searcherExecutor-5730-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard2_replica1] Registered new searcher Searcher@162a0be[dv_coll_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1623273 INFO (qtp10470628-10419) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623274 INFO (qtp10470628-10425) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 2
[junit4] 2> 1623283 INFO (qtp10470628-10419) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 11
[junit4] 2> 1623283 INFO (qtp27823741-10523) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:36322/solr/dv_coll_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 11
[junit4] 2> 1623283 INFO (qtp10470628-10433) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr path=/update params={_stateVer_=dv_coll:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 13
[junit4] 2> 1623291 INFO (qtp27823741-10420) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica1] webapp=/solr path=/update params={_stateVer_=dv_coll:3&wt=javabin&version=2}{add=[0 (1561252946287525888), 4 (1561252946291720192), 10005 (1561252946291720193), 12 (1561252946291720194), 15 (1561252946291720195), 16 (1561252946291720196), 20 (1561252946291720197), 22 (1561252946291720198), 34 (1561252946291720199), 35 (1561252946292768768), ... (16 adds)]} 0 4
[junit4] 2> 1623292 INFO (qtp10470628-10431) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr path=/update params={_stateVer_=dv_coll:3&wt=javabin&version=2}{add=[1 (1561252946287525888), 8 (1561252946291720192), 10 (1561252946291720193), 11 (1561252946291720194), 13 (1561252946291720195), 14 (1561252946291720196), 10015 (1561252946292768768), 10020 (1561252946292768769), 24 (1561252946292768770), 27 (1561252946292768771), ... (16 adds)]} 0 5
[junit4] 2> 1623292 INFO (qtp10470628-10419) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr path=/update params={_stateVer_=dv_coll:3&wt=javabin&version=2}{add=[2 (1561252946288574464), 3 (1561252946292768768), 6 (1561252946292768769), 7 (1561252946293817344), 9 (1561252946293817345), 10010 (1561252946293817346), 18 (1561252946293817347), 10025 (1561252946293817348), 26 (1561252946293817349), 30 (1561252946293817350), ... (14 adds)]} 0 5
[junit4] 2> 1623294 INFO (qtp27823741-10432) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard4_replica1] webapp=/solr path=/update params={_stateVer_=dv_coll:3&wt=javabin&version=2}{add=[10000 (1561252946291720192), 5 (1561252946294865920), 17 (1561252946294865921), 19 (1561252946294865922), 21 (1561252946294865923), 23 (1561252946294865924), 25 (1561252946294865925), 29 (1561252946294865926), 10030 (1561252946295914496), 33 (1561252946295914497), ... (13 adds)]} 0 4
[junit4] 2> 1623302 INFO (qtp27823741-10522) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623302 INFO (qtp27823741-10524) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623302 INFO (qtp10470628-10423) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623302 INFO (qtp10470628-10429) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1623302 INFO (qtp10470628-10423) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@107b847
[junit4] 2> 1623302 INFO (qtp27823741-10524) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@b327d9
[junit4] 2> 1623302 INFO (qtp27823741-10522) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@baf739
[junit4] 2> 1623302 INFO (qtp10470628-10429) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1a5b86f
[junit4] 2> 1623305 INFO (qtp27823741-10522) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@cfcf87[dv_coll_shard2_replica1] main]
[junit4] 2> 1623305 INFO (searcherExecutor-5730-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard2_replica1] Registered new searcher Searcher@cfcf87[dv_coll_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(6.4.3):C16)))}
[junit4] 2> 1623305 INFO (qtp27823741-10522) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623305 INFO (qtp27823741-10522) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:33968/solr/dv_coll_shard4_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 2
[junit4] 2> 1623305 INFO (qtp10470628-10423) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@bad08a[dv_coll_shard3_replica1] main]
[junit4] 2> 1623305 INFO (searcherExecutor-5746-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@bad08a[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(6.4.3):C14)))}
[junit4] 2> 1623305 INFO (qtp10470628-10423) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623305 INFO (qtp10470628-10423) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:33968/solr/dv_coll_shard4_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 3
[junit4] 2> 1623307 INFO (qtp10470628-10429) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@8b162c[dv_coll_shard1_replica1] main]
[junit4] 2> 1623307 INFO (searcherExecutor-5718-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard1_replica1] Registered new searcher Searcher@8b162c[dv_coll_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(6.4.3):C16)))}
[junit4] 2> 1623307 INFO (qtp10470628-10429) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623307 INFO (qtp27823741-10524) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@12a3987[dv_coll_shard4_replica1] main]
[junit4] 2> 1623307 INFO (qtp10470628-10429) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:33968/solr/dv_coll_shard4_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 5
[junit4] 2> 1623308 INFO (searcherExecutor-5738-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard4_replica1] Registered new searcher Searcher@12a3987[dv_coll_shard4_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.3):C13)))}
[junit4] 2> 1623308 INFO (qtp27823741-10524) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1623308 INFO (qtp27823741-10524) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard4_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:33968/solr/dv_coll_shard4_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 5
[junit4] 2> 1623308 INFO (qtp27823741-10523) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard4_replica1] webapp=/solr path=/update params={_stateVer_=dv_coll:3&commit=true&wt=javabin&version=2}{commit=} 0 11
[junit4] 2> 1623323 INFO (qtp10470628-10425) [ ] o.a.s.c.S.Request [dv_coll_shard1_replica1] webapp=/solr path=/select params={df=text&group.distributed.first=true&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=2048&start=0&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&rows=100&version=2&q=*:*&NOW=1488926836313&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=8
[junit4] 2> 1623323 INFO (qtp27823741-10426) [ ] o.a.s.c.S.Request [dv_coll_shard4_replica1] webapp=/solr path=/select params={df=text&group.distributed.first=true&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=2048&start=0&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard4_replica1/&rows=100&version=2&q=*:*&NOW=1488926836313&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=8
[junit4] 2> 1623323 INFO (qtp10470628-10421) [ ] o.a.s.c.S.Request [dv_coll_shard3_replica1] webapp=/solr path=/select params={df=text&group.distributed.first=true&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=2048&start=0&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard3_replica1/&rows=100&version=2&q=*:*&NOW=1488926836313&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=8
[junit4] 2> 1623323 INFO (qtp27823741-10420) [ ] o.a.s.c.S.Request [dv_coll_shard2_replica1] webapp=/solr path=/select params={df=text&group.distributed.first=true&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=2048&start=0&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard2_replica1/&rows=100&version=2&q=*:*&NOW=1488926836313&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=9
[junit4] 2> 1623337 INFO (qtp10470628-10431) [ ] o.a.s.c.S.Request [dv_coll_shard1_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=4&start=0&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1488926836313&group.topgroups.intGSF=1552238100&group.topgroups.intGSF=1552248107&group.topgroups.intGSF=1552258109&group.topgroups.intGSF=%01&group.topgroups.intGSF=1552268114&group.topgroups.intGSF=1552278116&group.topgroups.intGSF=1552288119&group.topgroups.intGSF=1552298121&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=7
[junit4] 2> 1623337 INFO (qtp27823741-10432) [ ] o.a.s.c.S.Request [dv_coll_shard2_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=4&start=0&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard2_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1488926836313&group.topgroups.intGSF=1552238100&group.topgroups.intGSF=1552248107&group.topgroups.intGSF=1552258109&group.topgroups.intGSF=%01&group.topgroups.intGSF=1552268114&group.topgroups.intGSF=1552278116&group.topgroups.intGSF=1552288119&group.topgroups.intGSF=1552298121&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=7
[junit4] 2> 1623337 INFO (qtp10470628-10483) [ ] o.a.s.c.S.Request [dv_coll_shard3_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=4&start=0&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard3_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1488926836313&group.topgroups.intGSF=1552238100&group.topgroups.intGSF=1552248107&group.topgroups.intGSF=1552258109&group.topgroups.intGSF=%01&group.topgroups.intGSF=1552268114&group.topgroups.intGSF=1552278116&group.topgroups.intGSF=1552288119&group.topgroups.intGSF=1552298121&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=7
[junit4] 2> 1623337 INFO (qtp27823741-10522) [ ] o.a.s.c.S.Request [dv_coll_shard4_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=4&start=0&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard4_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1488926836313&group.topgroups.intGSF=1552238100&group.topgroups.intGSF=1552248107&group.topgroups.intGSF=1552258109&group.topgroups.intGSF=%01&group.topgroups.intGSF=1552268114&group.topgroups.intGSF=1552278116&group.topgroups.intGSF=1552288119&group.topgroups.intGSF=1552298121&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=7
[junit4] 2> 1623342 INFO (qtp27823741-10524) [ ] o.a.s.c.S.Request [dv_coll_shard2_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&shards.purpose=64&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard2_replica1/&rows=100&version=2&q=*:*&NOW=1488926836313&ids=22,44,12,34,35,46,36,47,15,16,0,4,41,20,10005,43&isShard=true&wt=javabin&group.field=intGSF} status=0 QTime=0
[junit4] 2> 1623342 INFO (qtp27823741-10523) [ ] o.a.s.c.S.Request [dv_coll_shard4_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&shards.purpose=64&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard4_replica1/&rows=100&version=2&q=*:*&NOW=1488926836313&ids=33,23,45,25,10040,37,17,10030,29,19,5,10000,21&isShard=true&wt=javabin&group.field=intGSF} status=0 QTime=0
[junit4] 2> 1623343 INFO (qtp10470628-10423) [ ] o.a.s.c.S.Request [dv_coll_shard3_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&shards.purpose=64&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard3_replica1/&rows=100&version=2&q=*:*&NOW=1488926836313&ids=26,39,18,2,3,6,7,9,10010,10035,10045,10025,30,31&isShard=true&wt=javabin&group.field=intGSF} status=0 QTime=0
[junit4] 2> 1623342 INFO (qtp10470628-10429) [ ] o.a.s.c.S.Request [dv_coll_shard1_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&shards.purpose=64&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&rows=100&version=2&q=*:*&NOW=1488926836313&ids=11,13,24,14,48,27,38,10020,28,1,8,10015,40,42,10,32&isShard=true&wt=javabin&group.field=intGSF} status=0 QTime=0
[junit4] 2> 1623345 INFO (qtp27823741-10422) [ ] o.a.s.c.S.Request [dv_coll_shard4_replica1] webapp=/solr path=/select params={q=*:*&_stateVer_=dv_coll:3&group.limit=100&rows=100&wt=javabin&version=2&group.field=intGSF&group=true} status=0 QTime=34
[junit4] 2> 1623352 INFO (qtp27823741-10434) [ ] o.a.s.c.S.Request [dv_coll_shard2_replica1] webapp=/solr path=/select params={df=text&group.distributed.first=true&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=2048&start=0&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard2_replica1/&rows=100&version=2&q=*:*&NOW=1488926836351&isShard=true&wt=javabin&group.field=longGSF&group=true} status=0 QTime=0
[junit4] 2> 1623352 INFO (qtp10470628-10419) [ ] o.a.s.c.S.Request [dv_coll_shard1_replica1] webapp=/solr path=/select params={df=text&group.distributed.first=true&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=2048&start=0&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&rows=100&version=2&q=*:*&NOW=1488926836351&isShard=true&wt=javabin&group.field=longGSF&group=true} status=0 QTime=0
[junit4] 2> 1623352 INFO (qtp10470628-10433) [ ] o.a.s.c.S.Request [dv_coll_shard3_replica1] webapp=/solr path=/select params={df=text&group.distributed.first=true&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=2048&start=0&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard3_replica1/&rows=100&version=2&q=*:*&NOW=1488926836351&isShard=true&wt=javabin&group.field=longGSF&group=true} status=0 QTime=0
[junit4] 2> 1623352 INFO (qtp27823741-10420) [ ] o.a.s.c.S.Request [dv_coll_shard4_replica1] webapp=/solr path=/select params={df=text&group.distributed.first=true&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=2048&start=0&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard4_replica1/&rows=100&version=2&q=*:*&NOW=1488926836351&isShard=true&wt=javabin&group.field=longGSF&group=true} status=0 QTime=0
[junit4] 2> 1623356 INFO (qtp10470628-10423) [ ] o.a.s.c.S.Request [dv_coll_shard1_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=4&start=0&group.topgroups.longGSF=4081697807472812913&group.topgroups.longGSF=%01&group.topgroups.longGSF=4081697807472822916&group.topgroups.longGSF=4081697807472832924&group.topgroups.longGSF=4081697807472842925&group.topgroups.longGSF=4081697807472852931&group.topgroups.longGSF=4081697807472862935&group.topgroups.longGSF=4081697807472872942&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1488926836351&isShard=true&wt=javabin&group.field=longGSF&group=true} status=0 QTime=0
[junit4] 2> 1623358 INFO (qtp27823741-10522) [ ] o.a.s.c.S.Request [dv_coll_shard2_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=4&start=0&group.topgroups.longGSF=4081697807472812913&group.topgroups.longGSF=%01&group.topgroups.longGSF=4081697807472822916&group.topgroups.longGSF=4081697807472832924&group.topgroups.longGSF=4081697807472842925&group.topgroups.longGSF=4081697807472852931&group.topgroups.longGSF=4081697807472862935&group.topgroups.longGSF=4081697807472872942&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard2_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1488926836351&isShard=true&wt=javabin&group.field=longGSF&group=true} status=0 QTime=1
[junit4] 2> 1623359 INFO (qtp10470628-10431) [ ] o.a.s.c.S.Request [dv_coll_shard3_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=4&start=0&group.topgroups.longGSF=4081697807472812913&group.topgroups.longGSF=%01&group.topgroups.longGSF=4081697807472822916&group.topgroups.longGSF=4081697807472832924&group.topgroups.longGSF=4081697807472842925&group.topgroups.longGSF=4081697807472852931&group.topgroups.longGSF=4081697807472862935&group.topgroups.longGSF=4081697807472872942&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard3_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1488926836351&isShard=true&wt=javabin&group.field=longGSF&group=true} status=0 QTime=1
[junit4] 2> 1623359 INFO (qtp27823741-10432) [ ] o.a.s.c.S.Request [dv_coll_shard4_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&fl=id,score&shards.purpose=4&start=0&group.topgroups.longGSF=4081697807472812913&group.topgroups.longGSF=%01&group.topgroups.longGSF=4081697807472822916&group.topgroups.longGSF=4081697807472832924&group.topgroups.longGSF=4081697807472842925&group.topgroups.longGSF=4081697807472852931&group.topgroups.longGSF=4081697807472862935&group.topgroups.longGSF=4081697807472872942&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard4_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1488926836351&isShard=true&wt=javabin&group.field=longGSF&group=true} status=0 QTime=1
[junit4] 2> 1623361 INFO (qtp27823741-10523) [ ] o.a.s.c.S.Request [dv_coll_shard4_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&shards.purpose=64&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard4_replica1/&rows=100&version=2&q=*:*&NOW=1488926836351&ids=33,23,45,25,10040,37,17,10030,29,19,5,10000,21&isShard=true&wt=javabin&group.field=longGSF} status=0 QTime=0
[junit4] 2> 1623361 INFO (qtp27823741-10524) [ ] o.a.s.c.S.Request [dv_coll_shard2_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&shards.purpose=64&shard.url=https://127.0.0.1:33968/solr/dv_coll_shard2_replica1/&rows=100&version=2&q=*:*&NOW=1488926836351&ids=22,44,12,34,35,46,36,47,15,16,0,4,41,20,10005,43&isShard=true&wt=javabin&group.field=longGSF} status=0 QTime=0
[junit4] 2> 1623361 INFO (qtp10470628-10433) [ ] o.a.s.c.S.Request [dv_coll_shard1_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=dv_coll:3&group.limit=100&shards.purpose=64&shard.url=https://127.0.0.1:36322/solr/dv_coll_shard1_replica1/&rows=100&version=2&q=*:*&NOW=1488926836351&ids=11,13,24,14,48,27
[...truncated too long message...]
2> 1623590 INFO (coreCloseExecutor-5750-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard4_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@1743d49
[junit4] 2> 1623591 INFO (coreCloseExecutor-5751-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@8d8666
[junit4] 2> 1623592 INFO (zkCallback-1935-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1623595 INFO (zkCallback-1933-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1623595 INFO (coreCloseExecutor-5751-thread-2) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@12dcac4
[junit4] 2> 1623595 INFO (coreCloseExecutor-5750-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.dv_coll.shard4.replica1
[junit4] 2> 1623596 INFO (coreCloseExecutor-5751-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.dv_coll.shard1.replica1
[junit4] 2> 1623596 INFO (coreCloseExecutor-5750-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.dv_coll.shard2.replica1
[junit4] 2> 1623600 WARN (zkCallback-1933-thread-2) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1623600 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15aaaf476290004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 1623600 INFO (jetty-launcher-1924-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 1623600 INFO (jetty-launcher-1924-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@b19017{/solr,null,UNAVAILABLE}
[junit4] 2> 1623600 INFO (zkCallback-1935-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1623601 INFO (coreCloseExecutor-5751-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.dv_coll.shard3.replica1
[junit4] 2> 1623602 INFO (jetty-launcher-1924-thread-2) [ ] o.a.s.c.Overseer Overseer (id=97578308873027590-127.0.0.1:36322_solr-n_0000000000) closing
[junit4] 2> 1623602 INFO (OverseerStateUpdate-97578308873027590-127.0.0.1:36322_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:36322_solr
[junit4] 2> 1623603 WARN (zkCallback-1935-thread-3) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1623603 INFO (jetty-launcher-1924-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 1623603 INFO (jetty-launcher-1924-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1c04fa5{/solr,null,UNAVAILABLE}
[junit4] 2> 1623604 INFO (SUITE-DocValuesNotIndexedTest-seed#[8AA110EC2738523F]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:45091 45091
[junit4] 2> 1623611 INFO (Thread-2420) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:45091 45091
[junit4] 2> 1623611 WARN (Thread-2420) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/configs/conf1/managed-schema
[junit4] 2> 4 /solr/configs/conf1
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 2 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2> 2 /solr/configs/conf1/managed-schema
[junit4] 2> 2 /solr/collections/dv_coll/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/overseer/queue
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2> 3 /solr/overseer/collection-queue-work
[junit4] 2> 3 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> 1623613 INFO (SUITE-DocValuesNotIndexedTest-seed#[8AA110EC2738523F]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-6.4-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.DocValuesNotIndexedTest_8AA110EC2738523F-001
[junit4] 2> Mar 07, 2017 10:47:16 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 4 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62), sim=RandomSimilarity(queryNorm=false,coord=yes): {}, locale=ce-RU, timezone=SystemV/CST6CDT
[junit4] 2> NOTE: Linux 4.4.0-53-generic i386/Oracle Corporation 9-ea (32-bit)/cpus=12,threads=1,free=121185544,total=268435456
[junit4] 2> NOTE: All tests run in this JVM: [SpellPossibilityIteratorTest, UpdateParamsTest, TestJmxMonitoredMap, TestRuleBasedAuthorizationPlugin, ResponseLogComponentTest, TestTrackingShardHandlerFactory, MetricUtilsTest, CoreAdminHandlerTest, TestSort, MetricsHandlerTest, TestCoreDiscovery, SpatialHeatmapFacetsTest, OutOfBoxZkACLAndCredentialsProvidersTest, DistributedQueueTest, PrimitiveFieldTypeTest, MinimalSchemaTest, TestMacros, SharedFSAutoReplicaFailoverUtilsTest, TestReload, SolrCloudExampleTest, TestShortCircuitedRequests, CleanupOldIndexTest, SolrJmxReporterTest, TestClassicSimilarityFactory, TestManagedResourceStorage, TestRebalanceLeaders, GraphQueryTest, TestSolrFieldCacheMBean, DocValuesMultiTest, SaslZkACLProviderTest, TestConfig, TestHighFrequencyDictionaryFactory, UUIDUpdateProcessorFallbackTest, TestClusterStateMutator, TestSolrDeletionPolicy1, TestSolrQueryParser, BadIndexSchemaTest, DeleteReplicaTest, TestGraphTermsQParserPlugin, TestGeoJSONResponseWriter, TestSolrJ, LeaderInitiatedRecoveryOnShardRestartTest, TestCloudDeleteByQuery, TestLeaderInitiatedRecoveryThread, TestAnalyzedSuggestions, BitVectorTest, TestCustomSort, CoreSorterTest, TemplateUpdateProcessorTest, TestOrdValues, ParsingFieldUpdateProcessorsTest, CollectionsAPISolrJTest, TestLMJelinekMercerSimilarityFactory, TestPerFieldSimilarityClassic, HardAutoCommitTest, TestHdfsCloudBackupRestore, FacetPivotSmallTest, TestTolerantSearch, TestRestoreCore, SolrPluginUtilsTest, PrimUtilsTest, RemoteQueryErrorTest, HdfsChaosMonkeySafeLeaderTest, TestExtendedDismaxParser, TestSchemaNameResource, TestIndexingPerformance, RequestLoggingTest, TermVectorComponentDistributedTest, TestPushWriter, CollectionStateFormat2Test, LeaderElectionTest, TestJsonFacetRefinement, ConnectionManagerTest, TestSolrQueryResponse, TestRecovery, TestReloadDeadlock, FieldMutatingUpdateProcessorTest, TestDynamicLoading, TestCloudPseudoReturnFields, BinaryUpdateRequestHandlerTest, TestDocBasedVersionConstraints, HdfsBasicDistributedZk2Test, DataDrivenBlockJoinTest, AssignTest, UnloadDistributedZkTest, SortSpecParsingTest, OverseerTaskQueueTest, RestartWhileUpdatingTest, OpenExchangeRatesOrgProviderTest, AddBlockUpdateTest, BadComponentTest, TestSchemaVersionResource, TestMiniSolrCloudCluster, TestXIncludeConfig, TestDistributedStatsComponentCardinality, TestBinaryResponseWriter, TestInitParams, TestConfigSets, FieldAnalysisRequestHandlerTest, SuggesterTest, TestLFUCache, TestReversedWildcardFilterFactory, TestSchemaManager, CheckHdfsIndexTest, LukeRequestHandlerTest, HdfsSyncSliceTest, TestSolrQueryParserResource, CloneFieldUpdateProcessorFactoryTest, ForceLeaderTest, TestConfigOverlay, TestOnReconnectListenerSupport, CollectionsAPIDistributedZkTest, BasicZkTest, RecoveryZkTest, ClusterStateUpdateTest, TestRandomFaceting, ZkCLITest, TestHashPartitioner, TestJoin, TestRangeQuery, TestCoreContainer, StatsComponentTest, SolrCmdDistributorTest, TestFunctionQuery, BasicFunctionalityTest, DirectUpdateHandlerTest, TestBadConfig, TestIndexSearcher, ShowFileRequestHandlerTest, SimplePostToolTest, SpellCheckCollatorTest, PolyFieldTest, NoCacheHeaderTest, SolrCoreCheckLockOnStartupTest, TestUpdate, DirectUpdateHandlerOptimizeTest, DefaultValueUpdateProcessorTest, SortByFunctionTest, XsltUpdateRequestHandlerTest, CacheHeaderTest, TestWriterPerf, TestQueryTypes, FileBasedSpellCheckerTest, DocumentBuilderTest, MoreLikeThisHandlerTest, IndexSchemaRuntimeFieldTest, TestCollationField, ReturnFieldsTest, JSONWriterTest, QueryParsingTest, TestPHPSerializedResponseWriter, CSVRequestHandlerTest, SearchHandlerTest, TestMergePolicyConfig, NumericFieldsTest, OutputWriterTest, ExternalFileFieldSortTest, TestPostingsSolrHighlighter, TestPhraseSuggestions, SynonymTokenizerTest, TestSweetSpotSimilarityFactory, TestIBSimilarityFactory, TimeZoneUtilsTest, PluginInfoTest, ChaosMonkeyNothingIsSafeTest, TestJettySolrRunner, ConnectionReuseTest, BaseCdcrDistributedZkTest, CdcrBootstrapTest, DeleteInactiveReplicaTest, DeleteShardTest, DistribDocExpirationUpdateProcessorTest, DocValuesNotIndexedTest]
[junit4] Completed [473/680 (1!)] on J2 in 4.99s, 4 tests, 1 failure <<< FAILURES!
[...truncated 52210 lines...]