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/01/30 18:48:03 UTC
[JENKINS-EA] Lucene-Solr-6.x-Linux (64bit/jdk-9-ea+153) - Build #
2768 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Linux/2768/
Java: 64bit/jdk-9-ea+153 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingDVOnly
Error Message:
Unexpected number of elements in the group for intGSF: 5
Stack Trace:
java.lang.AssertionError: Unexpected number of elements in the group for intGSF: 5
at __randomizedtesting.SeedInfo.seed([6E668EC65E6AFB57:F5DDE09E1332C909]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingDVOnly(DocValuesNotIndexedTest.java:376)
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:543)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 11757 lines...]
[junit4] Suite: org.apache.solr.cloud.DocValuesNotIndexedTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/init-core-data-001
[junit4] 2> 954914 INFO (SUITE-DocValuesNotIndexedTest-seed#[6E668EC65E6AFB57]-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> 954916 INFO (SUITE-DocValuesNotIndexedTest-seed#[6E668EC65E6AFB57]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001
[junit4] 2> 954916 INFO (SUITE-DocValuesNotIndexedTest-seed#[6E668EC65E6AFB57]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 954916 INFO (Thread-1925) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 954916 INFO (Thread-1925) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 955016 INFO (SUITE-DocValuesNotIndexedTest-seed#[6E668EC65E6AFB57]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:34831
[junit4] 2> 955022 INFO (jetty-launcher-1270-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 955023 INFO (jetty-launcher-1270-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1f762ef4{/solr,null,AVAILABLE}
[junit4] 2> 955023 INFO (jetty-launcher-1270-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 955024 INFO (jetty-launcher-1270-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@77f68f37{SSL,[ssl, http/1.1]}{127.0.0.1:43394}
[junit4] 2> 955024 INFO (jetty-launcher-1270-thread-2) [ ] o.e.j.s.Server Started @956666ms
[junit4] 2> 955024 INFO (jetty-launcher-1270-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43394}
[junit4] 2> 955024 ERROR (jetty-launcher-1270-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 955024 INFO (jetty-launcher-1270-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.5.0
[junit4] 2> 955024 INFO (jetty-launcher-1270-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 955024 INFO (jetty-launcher-1270-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 955024 INFO (jetty-launcher-1270-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-30T18:22:09.418548Z
[junit4] 2> 955024 INFO (jetty-launcher-1270-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@29432ab0{/solr,null,AVAILABLE}
[junit4] 2> 955025 INFO (jetty-launcher-1270-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@56aba2bb{SSL,[ssl, http/1.1]}{127.0.0.1:33764}
[junit4] 2> 955025 INFO (jetty-launcher-1270-thread-1) [ ] o.e.j.s.Server Started @956667ms
[junit4] 2> 955025 INFO (jetty-launcher-1270-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=33764}
[junit4] 2> 955025 ERROR (jetty-launcher-1270-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 955025 INFO (jetty-launcher-1270-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.5.0
[junit4] 2> 955025 INFO (jetty-launcher-1270-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 955025 INFO (jetty-launcher-1270-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 955025 INFO (jetty-launcher-1270-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 955025 INFO (jetty-launcher-1270-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-30T18:22:09.419913Z
[junit4] 2> 955027 INFO (jetty-launcher-1270-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 955038 INFO (jetty-launcher-1270-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 955040 INFO (jetty-launcher-1270-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34831/solr
[junit4] 2> 955044 INFO (jetty-launcher-1270-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 955046 INFO (jetty-launcher-1270-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34831/solr
[junit4] 2> 955050 INFO (jetty-launcher-1270-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43394_solr
[junit4] 2> 955051 INFO (jetty-launcher-1270-thread-2) [ ] o.a.s.c.Overseer Overseer (id=97373423488925700-127.0.0.1:43394_solr-n_0000000000) starting
[junit4] 2> 955051 INFO (jetty-launcher-1270-thread-1) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33764_solr
[junit4] 2> 955052 INFO (zkCallback-1282-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 955052 INFO (zkCallback-1277-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 955055 INFO (jetty-launcher-1270-thread-2) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43394_solr
[junit4] 2> 955055 INFO (zkCallback-1277-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 955055 INFO (zkCallback-1282-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 955073 INFO (jetty-launcher-1270-thread-2) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001/node2/.
[junit4] 2> 955074 INFO (jetty-launcher-1270-thread-1) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001/node1/.
[junit4] 2> 955266 INFO (SUITE-DocValuesNotIndexedTest-seed#[6E668EC65E6AFB57]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 955266 INFO (SUITE-DocValuesNotIndexedTest-seed#[6E668EC65E6AFB57]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34831/solr ready
[junit4] 2> 955319 INFO (qtp695883925-7511) [ ] 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> 955320 INFO (OverseerThreadFactory-3251-thread-1) [ ] o.a.s.c.CreateCollectionCmd Create collection dv_coll
[junit4] 2> 955427 INFO (qtp695883925-7517) [ ] 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> 955427 INFO (qtp695883925-7513) [ ] 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> 955471 INFO (qtp1337149954-7508) [ ] 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> 955471 INFO (qtp1337149954-7507) [ ] 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> 955574 INFO (zkCallback-1277-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> 955574 INFO (zkCallback-1282-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> 956432 INFO (qtp695883925-7513) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 956442 INFO (qtp695883925-7517) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 956446 INFO (qtp695883925-7513) [ ] o.a.s.s.IndexSchema [dv_coll_shard1_replica1] Schema name=minimal
[junit4] 2> 956447 INFO (qtp695883925-7513) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 956448 INFO (qtp695883925-7513) [ ] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard1_replica1' using configuration from collection dv_coll
[junit4] 2> 956448 INFO (qtp695883925-7517) [ ] o.a.s.s.IndexSchema [dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 956448 INFO (qtp695883925-7513) [ ] o.a.s.c.SolrCore [[dv_coll_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001/node1/dv_coll_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001/node1/./dv_coll_shard1_replica1/data/]
[junit4] 2> 956450 INFO (qtp695883925-7517) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 956450 INFO (qtp695883925-7517) [ ] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard3_replica1' using configuration from collection dv_coll
[junit4] 2> 956451 INFO (qtp695883925-7517) [ ] o.a.s.c.SolrCore [[dv_coll_shard3_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001/node1/dv_coll_shard3_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001/node1/./dv_coll_shard3_replica1/data/]
[junit4] 2> 956476 INFO (qtp1337149954-7508) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 956476 INFO (qtp1337149954-7507) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 956479 INFO (qtp695883925-7513) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 956479 INFO (qtp695883925-7513) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 956481 INFO (qtp1337149954-7507) [ ] o.a.s.s.IndexSchema [dv_coll_shard2_replica1] Schema name=minimal
[junit4] 2> 956481 INFO (qtp1337149954-7508) [ ] o.a.s.s.IndexSchema [dv_coll_shard4_replica1] Schema name=minimal
[junit4] 2> 956481 INFO (qtp695883925-7513) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 956481 INFO (qtp695883925-7513) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 956483 INFO (qtp1337149954-7508) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 956483 INFO (qtp1337149954-7507) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 956483 INFO (qtp1337149954-7508) [ ] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard4_replica1' using configuration from collection dv_coll
[junit4] 2> 956483 INFO (qtp1337149954-7507) [ ] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard2_replica1' using configuration from collection dv_coll
[junit4] 2> 956484 INFO (qtp1337149954-7508) [ ] o.a.s.c.SolrCore [[dv_coll_shard4_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001/node2/dv_coll_shard4_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001/node2/./dv_coll_shard4_replica1/data/]
[junit4] 2> 956484 INFO (qtp1337149954-7507) [ ] o.a.s.c.SolrCore [[dv_coll_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001/node2/dv_coll_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001/node2/./dv_coll_shard2_replica1/data/]
[junit4] 2> 956498 INFO (qtp695883925-7513) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@30dfe58c[dv_coll_shard1_replica1] main]
[junit4] 2> 956498 INFO (qtp695883925-7513) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 956498 INFO (qtp695883925-7513) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 956498 INFO (qtp695883925-7513) [ ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 956499 INFO (qtp695883925-7513) [ ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 956499 INFO (qtp695883925-7513) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 956499 INFO (searcherExecutor-3256-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard1_replica1] Registered new searcher Searcher@30dfe58c[dv_coll_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 956499 INFO (qtp695883925-7513) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1557974777481658368
[junit4] 2> 956503 INFO (qtp695883925-7513) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 956503 INFO (qtp695883925-7513) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 956503 INFO (qtp695883925-7513) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:33764/solr/dv_coll_shard1_replica1/
[junit4] 2> 956503 INFO (qtp695883925-7513) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 956503 INFO (qtp695883925-7513) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:33764/solr/dv_coll_shard1_replica1/ has no replicas
[junit4] 2> 956505 INFO (qtp695883925-7513) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:33764/solr/dv_coll_shard1_replica1/ shard1
[junit4] 2> 956514 INFO (qtp695883925-7517) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 956514 INFO (qtp695883925-7517) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 956517 INFO (qtp695883925-7517) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 956517 INFO (qtp695883925-7517) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 956526 INFO (qtp695883925-7517) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1710b53c[dv_coll_shard3_replica1] main]
[junit4] 2> 956526 INFO (qtp1337149954-7507) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 956526 INFO (qtp1337149954-7507) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 956526 INFO (qtp1337149954-7508) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 956526 INFO (qtp1337149954-7508) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 956528 INFO (qtp695883925-7517) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 956528 INFO (qtp695883925-7517) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 956528 INFO (qtp695883925-7517) [ ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 956528 INFO (qtp1337149954-7507) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 956528 INFO (qtp1337149954-7507) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 956528 INFO (qtp695883925-7517) [ ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 956528 INFO (qtp695883925-7517) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 956528 INFO (qtp1337149954-7508) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 956528 INFO (qtp1337149954-7508) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 956528 INFO (searcherExecutor-3257-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@1710b53c[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 956529 INFO (qtp695883925-7517) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1557974777513115648
[junit4] 2> 956533 INFO (qtp1337149954-7507) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7bbaec24[dv_coll_shard2_replica1] main]
[junit4] 2> 956533 INFO (qtp1337149954-7508) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@25af98d7[dv_coll_shard4_replica1] main]
[junit4] 2> 956534 INFO (qtp1337149954-7507) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 956534 INFO (qtp1337149954-7508) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 956534 INFO (qtp1337149954-7507) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 956534 INFO (qtp1337149954-7507) [ ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 956534 INFO (qtp1337149954-7508) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 956534 INFO (qtp695883925-7517) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 956534 INFO (qtp1337149954-7508) [ ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 956534 INFO (qtp695883925-7517) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 956534 INFO (qtp695883925-7517) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:33764/solr/dv_coll_shard3_replica1/
[junit4] 2> 956534 INFO (qtp695883925-7517) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 956534 INFO (qtp1337149954-7507) [ ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 956534 INFO (qtp695883925-7517) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:33764/solr/dv_coll_shard3_replica1/ has no replicas
[junit4] 2> 956534 INFO (qtp1337149954-7508) [ ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 956534 INFO (qtp1337149954-7507) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 956534 INFO (qtp1337149954-7508) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 956535 INFO (searcherExecutor-3263-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard2_replica1] Registered new searcher Searcher@7bbaec24[dv_coll_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 956535 INFO (searcherExecutor-3262-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard4_replica1] Registered new searcher Searcher@25af98d7[dv_coll_shard4_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 956535 INFO (qtp1337149954-7507) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1557974777519407104
[junit4] 2> 956535 INFO (qtp1337149954-7508) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1557974777519407104
[junit4] 2> 956536 INFO (qtp695883925-7517) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:33764/solr/dv_coll_shard3_replica1/ shard3
[junit4] 2> 956538 INFO (qtp1337149954-7507) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 956538 INFO (qtp1337149954-7507) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 956538 INFO (qtp1337149954-7508) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 956538 INFO (qtp1337149954-7508) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 956538 INFO (qtp1337149954-7507) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:43394/solr/dv_coll_shard2_replica1/
[junit4] 2> 956538 INFO (qtp1337149954-7508) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:43394/solr/dv_coll_shard4_replica1/
[junit4] 2> 956538 INFO (qtp1337149954-7507) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 956539 INFO (qtp1337149954-7508) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 956539 INFO (qtp1337149954-7507) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:43394/solr/dv_coll_shard2_replica1/ has no replicas
[junit4] 2> 956539 INFO (qtp1337149954-7508) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:43394/solr/dv_coll_shard4_replica1/ has no replicas
[junit4] 2> 956540 INFO (qtp1337149954-7507) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:43394/solr/dv_coll_shard2_replica1/ shard2
[junit4] 2> 956540 INFO (qtp1337149954-7508) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:43394/solr/dv_coll_shard4_replica1/ shard4
[junit4] 2> 956643 INFO (zkCallback-1277-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> 956643 INFO (zkCallback-1282-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> 956656 INFO (qtp695883925-7513) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 956658 INFO (qtp695883925-7513) [ ] 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=1231
[junit4] 2> 956686 INFO (qtp695883925-7517) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 956688 INFO (qtp695883925-7517) [ ] 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=1260
[junit4] 2> 956691 INFO (qtp1337149954-7507) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 956691 INFO (qtp1337149954-7508) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 956692 INFO (qtp1337149954-7507) [ ] 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=1221
[junit4] 2> 956692 INFO (qtp1337149954-7508) [ ] 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=1221
[junit4] 2> 956694 INFO (qtp695883925-7511) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 956793 INFO (zkCallback-1277-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> 956793 INFO (zkCallback-1282-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> 957322 INFO (OverseerCollectionConfigSetProcessor-97373423488925700-127.0.0.1:43394_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> 957694 INFO (qtp695883925-7511) [ ] 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> 957699 INFO (qtp695883925-7516) [ ] o.a.s.s.SchemaManager managed schema loaded . version : 0
[junit4] 2> 957700 INFO (qtp695883925-7516) [ ] o.a.s.s.IndexSchema [dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 957701 INFO (qtp695883925-7516) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 957708 INFO (zkCallback-1282-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> 957708 INFO (zkCallback-1277-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> 957708 INFO (zkCallback-1282-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> 957708 INFO (zkCallback-1277-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> 957708 INFO (qtp695883925-7516) [ ] o.a.s.c.ZkController Persisted config data to node /configs/conf1/managed-schema
[junit4] 2> 957708 INFO (zkCallback-1277-thread-2) [ ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 1 from ZooKeeper
[junit4] 2> 957708 INFO (zkCallback-1282-thread-2) [ ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 1 from ZooKeeper
[junit4] 2> 957708 INFO (zkCallback-1277-thread-1) [ ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 1 from ZooKeeper
[junit4] 2> 957710 INFO (zkCallback-1282-thread-2) [ ] o.a.s.s.IndexSchema [dv_coll_shard1_replica1] Schema name=minimal
[junit4] 2> 957710 INFO (zkCallback-1277-thread-1) [ ] o.a.s.s.IndexSchema [dv_coll_shard4_replica1] Schema name=minimal
[junit4] 2> 957710 INFO (zkCallback-1277-thread-2) [ ] o.a.s.s.IndexSchema [dv_coll_shard2_replica1] Schema name=minimal
[junit4] 2> 957715 INFO (qtp695883925-7516) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 957719 INFO (zkCallback-1282-thread-2) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 957719 INFO (zkCallback-1282-thread-2) [ ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 10 ms
[junit4] 2> 957719 INFO (zkCallback-1277-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 957719 INFO (zkCallback-1277-thread-1) [ ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 10 ms
[junit4] 2> 957719 INFO (zkCallback-1277-thread-2) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 957719 INFO (Thread-1946) [ ] o.a.s.c.SolrCore config update listener called for core dv_coll_shard4_replica1
[junit4] 2> 957719 INFO (Thread-1947) [ ] o.a.s.c.SolrCore config update listener called for core dv_coll_shard1_replica1
[junit4] 2> 957719 INFO (zkCallback-1277-thread-2) [ ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 10 ms
[junit4] 2> 957720 INFO (Thread-1946) [ ] o.a.s.c.SolrCore config update listener called for core dv_coll_shard2_replica1
[junit4] 2> 957720 INFO (Thread-1947) [ ] o.a.s.c.SolrCore config update listener called for core dv_coll_shard3_replica1
[junit4] 2> 957721 INFO (Thread-1947) [ ] o.a.s.c.SolrCore core reload dv_coll_shard3_replica1
[junit4] 2> 957724 INFO (qtp695883925-7516) [ ] o.a.s.s.IndexSchema [dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 957748 INFO (qtp695883925-7516) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 957749 INFO (qtp695883925-7516) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'dv_coll_shard3_replica1' using configuration from collection dv_coll
[junit4] 2> 957749 INFO (qtp695883925-7516) [ ] o.a.s.c.SolrCore [[dv_coll_shard3_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001/node1/dv_coll_shard3_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001/node1/./dv_coll_shard3_replica1/data/]
[junit4] 2> 957758 INFO (qtp695883925-7516) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 957758 INFO (qtp695883925-7516) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 957758 INFO (qtp695883925-7516) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@735c98e1[dv_coll_shard3_replica1] main]
[junit4] 2> 957759 INFO (qtp695883925-7516) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 957759 INFO (qtp695883925-7516) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 957759 INFO (qtp695883925-7516) [ ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 957759 INFO (qtp695883925-7516) [ ] o.a.s.s.ZkIndexSchemaReader Current schema version 1 is already the latest
[junit4] 2> 957759 INFO (qtp695883925-7516) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 957759 INFO (searcherExecutor-3276-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@735c98e1[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 957759 INFO (qtp695883925-7516) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1557974778802864128
[junit4] 2> 957782 INFO (qtp695883925-7516) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 957783 INFO (qtp695883925-7516) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6b237f04[dv_coll_shard3_replica1] main]
[junit4] 2> 957783 INFO (searcherExecutor-3276-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@6b237f04[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 957783 INFO (qtp695883925-7516) [ ] 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> 957783 INFO (zkCallback-1282-thread-1) [ ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 1 from ZooKeeper
[junit4] 2> 957784 INFO (zkCallback-1282-thread-1) [ ] o.a.s.s.IndexSchema [dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 957788 INFO (qtp1337149954-7507) [ ] 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> 957791 INFO (Thread-1947) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 957792 INFO (qtp695883925-7514) [ ] 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> 957792 INFO (zkCallback-1282-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 957792 INFO (zkCallback-1282-thread-1) [ ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 8 ms
[junit4] 2> 957793 INFO (qtp1337149954-7501) [ ] 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> 957793 INFO (qtp695883925-7516) [ ] o.a.s.s.ManagedIndexSchema Took 10.0ms for 3 replicas to apply schema update version 1 for collection dv_coll
[junit4] 2> 957793 INFO (qtp695883925-7516) [ ] o.a.s.c.S.Request [dv_coll_shard3_replica1] webapp=/solr path=/schema params={wt=javabin&version=2} status=0 QTime=95
[junit4] 2> 957793 INFO (qtp695883925-7516) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@670c89a6
[junit4] 2> 957794 INFO (qtp695883925-7516) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.dv_coll.shard3.replica1
[junit4] 2> 957804 INFO (TEST-DocValuesNotIndexedTest.testGroupingDVOnly-seed#[6E668EC65E6AFB57]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testGroupingDVOnly
[junit4] 2> 957807 INFO (Thread-1947) [ ] o.a.s.s.IndexSchema [dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 957812 INFO (qtp695883925-7565) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:33764/solr/dv_coll_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1557974778856341504)} 0 2
[junit4] 2> 957815 INFO (qtp1337149954-7506) [ ] 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:33764/solr/dv_coll_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1557974778858438656)} 0 2
[junit4] 2> 957815 INFO (qtp1337149954-7508) [ ] 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:33764/solr/dv_coll_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1557974778858438656)} 0 2
[junit4] 2> 957815 INFO (Thread-1947) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 957815 INFO (qtp695883925-7518) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1557974778853195776)} 0 9
[junit4] 2> 957816 INFO (Thread-1947) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'dv_coll_shard3_replica1' using configuration from collection dv_coll
[junit4] 2> 957816 INFO (Thread-1947) [ ] o.a.s.c.SolrCore [[dv_coll_shard3_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001/node1/dv_coll_shard3_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001/tempDir-001/node1/./dv_coll_shard3_replica1/data/]
[junit4] 2> 957820 INFO (qtp695883925-7511) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 957820 INFO (qtp695883925-7511) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 957820 INFO (qtp1337149954-7506) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 957820 INFO (qtp1337149954-7506) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 957821 INFO (qtp695883925-7516) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 957821 INFO (qtp695883925-7516) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 957821 INFO (qtp695883925-7516) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 957821 INFO (qtp695883925-7516) [ ] 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:43394/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0
[junit4] 2> 957821 INFO (qtp1337149954-7504) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 957821 INFO (qtp1337149954-7504) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 957821 INFO (qtp695883925-7511) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2672b0eb[dv_coll_shard1_replica1] main]
[junit4] 2> 957821 INFO (qtp1337149954-7506) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@61772698[dv_coll_shard4_replica1] main]
[junit4] 2> 957822 INFO (qtp1337149954-7504) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@427b512c[dv_coll_shard2_replica1] main]
[junit4] 2> 957822 INFO (qtp695883925-7511) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 957822 INFO (searcherExecutor-3262-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard4_replica1] Registered new searcher Searcher@61772698[dv_coll_shard4_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 957822 INFO (searcherExecutor-3256-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard1_replica1] Registered new searcher Searcher@2672b0eb[dv_coll_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 957822 INFO (qtp1337149954-7506) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 957822 INFO (qtp695883925-7511) [ ] 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:43394/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1
[junit4] 2> 957822 INFO (qtp1337149954-7506) [ ] 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:43394/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1
[junit4] 2> 957822 INFO (qtp1337149954-7504) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 957822 INFO (searcherExecutor-3263-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard2_replica1] Registered new searcher Searcher@427b512c[dv_coll_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 957822 INFO (qtp1337149954-7504) [ ] 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:43394/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1
[junit4] 2> 957822 INFO (qtp1337149954-7508) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica1] webapp=/solr path=/update params={_stateVer_=dv_coll:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 4
[junit4] 2> 957828 INFO (Thread-1947) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 957829 INFO (Thread-1947) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 957829 INFO (Thread-1947) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@450fcb58[dv_coll_shard3_replica1] main]
[junit4] 2> 957829 INFO (Thread-1947) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 957830 INFO (Thread-1947) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 957830 INFO (Thread-1947) [ ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 957830 INFO (Thread-1947) [ ] o.a.s.s.ZkIndexSchemaReader Current schema version 1 is already the latest
[junit4] 2> 957830 INFO (Thread-1947) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 957831 INFO (searcherExecutor-3281-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@450fcb58[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 957834 INFO (qtp1337149954-7508) [ ] 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 (1557974778878361600), 5 (1557974778881507328), 17 (1557974778881507329), 19 (1557974778881507330), 21 (1557974778881507331), 23 (1557974778881507332), 25 (1557974778881507333), 29 (1557974778881507334), 10030 (1557974778881507335), 33 (1557974778881507336), ... (13 adds)]} 0 3
[junit4] 2> 957836 INFO (qtp1337149954-7503) [ ] 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 (1557974778878361600), 4 (1557974778881507328), 10005 (1557974778881507329), 12 (1557974778882555904), 15 (1557974778882555905), 16 (1557974778882555906), 20 (1557974778882555907), 22 (1557974778882555908), 34 (1557974778882555909), 35 (1557974778882555910), ... (16 adds)]} 0 5
[junit4] 2> 957836 INFO (qtp695883925-7514) [ ] 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 (1557974778878361600), 8 (1557974778882555904), 10 (1557974778882555905), 11 (1557974778882555906), 13 (1557974778882555907), 14 (1557974778882555908), 10015 (1557974778883604480), 10020 (1557974778883604481), 24 (1557974778883604482), 27 (1557974778883604483), ... (16 adds)]} 0 5
[junit4] 2> 957878 INFO (Thread-1947) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 957882 INFO (qtp695883925-7565) [ ] 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 (1557974778880458752), 3 (1557974778883604480), 6 (1557974778930790400), 7 (1557974778931838976), 9 (1557974778931838977), 10010 (1557974778931838978), 18 (1557974778931838979), 10025 (1557974778931838980), 26 (1557974778931838981), 30 (1557974778931838982), ... (14 adds)]} 0 51
[junit4] 2> 957886 INFO (qtp1337149954-7507) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 957886 INFO (qtp695883925-7512) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 957886 INFO (qtp695883925-7518) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 957886 INFO (qtp695883925-7512) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@62d9f3
[junit4] 2> 957886 INFO (qtp695883925-7518) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@40e26726
[junit4] 2> 957886 INFO (qtp1337149954-7507) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5ea58642
[junit4] 2> 957886 INFO (qtp1337149954-7598) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 957887 INFO (qtp1337149954-7598) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@166a049f
[junit4] 2> 957928 INFO (Thread-1947) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@10f3e839[dv_coll_shard3_replica1] main]
[junit4] 2> 957928 INFO (searcherExecutor-3281-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@10f3e839[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C1)))}
[junit4] 2> 958014 INFO (qtp695883925-7518) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@395b283d[dv_coll_shard1_replica1] main]
[junit4] 2> 958014 INFO (searcherExecutor-3256-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard1_replica1] Registered new searcher Searcher@395b283d[dv_coll_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C16)))}
[junit4] 2> 958014 INFO (qtp695883925-7518) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958014 INFO (qtp695883925-7518) [ ] 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:43394/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 127
[junit4] 2> 958029 INFO (qtp1337149954-7507) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@37265bd8[dv_coll_shard2_replica1] main]
[junit4] 2> 958029 INFO (qtp1337149954-7507) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958029 INFO (searcherExecutor-3263-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard2_replica1] Registered new searcher Searcher@37265bd8[dv_coll_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C16)))}
[junit4] 2> 958029 INFO (qtp1337149954-7507) [ ] 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:43394/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 142
[junit4] 2> 958051 INFO (qtp1337149954-7598) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6a959dfa[dv_coll_shard4_replica1] main]
[junit4] 2> 958051 INFO (searcherExecutor-3262-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard4_replica1] Registered new searcher Searcher@6a959dfa[dv_coll_shard4_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C13)))}
[junit4] 2> 958051 INFO (qtp1337149954-7598) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958051 INFO (qtp1337149954-7598) [ ] 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:43394/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 164
[junit4] 2> 958066 INFO (qtp695883925-7512) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@71151261[dv_coll_shard3_replica1] main]
[junit4] 2> 958066 INFO (qtp695883925-7512) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958066 INFO (searcherExecutor-3276-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@71151261[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C1) Uninverting(_1(6.5.0):C13)))}
[junit4] 2> 958066 INFO (qtp695883925-7512) [ ] 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:43394/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 180
[junit4] 2> 958067 INFO (qtp695883925-7512) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@2125508
[junit4] 2> 958067 INFO (qtp695883925-7512) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.dv_coll.shard3.replica1
[junit4] 2> 958067 INFO (qtp1337149954-7502) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica1] webapp=/solr path=/update params={_stateVer_=dv_coll:3&commit=true&wt=javabin&version=2}{commit=} 0 183
[junit4] 2> 958085 INFO (qtp1337149954-7503) [ ] 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:43394/solr/dv_coll_shard4_replica1/&rows=100&version=2&q=*:*&NOW=1485800532463&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=11
[junit4] 2> 958085 INFO (qtp1337149954-7507) [ ] 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:43394/solr/dv_coll_shard2_replica1/&rows=100&version=2&q=*:*&NOW=1485800532463&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=11
[junit4] 2> 958085 INFO (qtp695883925-7518) [ ] 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:33764/solr/dv_coll_shard3_replica1/&rows=100&version=2&q=*:*&NOW=1485800532463&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=11
[junit4] 2> 958085 INFO (qtp695883925-7565) [ ] 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:33764/solr/dv_coll_shard1_replica1/&rows=100&version=2&q=*:*&NOW=1485800532463&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=11
[junit4] 2> 958098 INFO (qtp695883925-7511) [ ] 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:33764/solr/dv_coll_shard3_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1485800532463&group.topgroups.intGSF=61592275&group.topgroups.intGSF=%01&group.topgroups.intGSF=61602282&group.topgroups.intGSF=61612285&group.topgroups.intGSF=61622293&group.topgroups.intGSF=61632301&group.topgroups.intGSF=61642310&group.topgroups.intGSF=61652317&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=7
[junit4] 2> 958098 INFO (qtp1337149954-7502) [ ] 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:43394/solr/dv_coll_shard4_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1485800532463&group.topgroups.intGSF=61592275&group.topgroups.intGSF=%01&group.topgroups.intGSF=61602282&group.topgroups.intGSF=61612285&group.topgroups.intGSF=61622293&group.topgroups.intGSF=61632301&group.topgroups.intGSF=61642310&group.topgroups.intGSF=61652317&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=7
[junit4] 2> 958099 INFO (qtp1337149954-7598) [ ] 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:43394/solr/dv_coll_shard2_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1485800532463&group.topgroups.intGSF=61592275&group.topgroups.intGSF=%01&group.topgroups.intGSF=61602282&group.topgroups.intGSF=61612285&group.topgroups.intGSF=61622293&group.topgroups.intGSF=61632301&group.topgroups.intGSF=61642310&group.topgroups.intGSF=61652317&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=7
[junit4] 2> 958099 INFO (qtp695883925-7512) [ ] 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:33764/solr/dv_coll_shard1_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1485800532463&group.topgroups.intGSF=61592275&group.topgroups.intGSF=%01&group.topgroups.intGSF=61602282&group.topgroups.intGSF=61612285&group.topgroups.intGSF=61622293&group.topgroups.intGSF=61632301&group.topgroups.intGSF=61642310&group.topgroups.intGSF=61652317&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=7
[junit4] 2> 958104 INFO (qtp695883925-7513) [ ] 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:33764/solr/dv_coll_shard3_replica1/&rows=100&version=2&q=*:*&NOW=1485800532463&ids=2&isShard=true&wt=javabin&group.field=intGSF} status=0 QTime=0
[junit4] 2> 958104 INFO (qtp1337149954-7508) [ ] 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:43394/solr/dv_coll_shard4_replica1/&rows=100&version=2&q=*:*&NOW=1485800532463&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> 958104 INFO (qtp1337149954-7504) [ ] 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:43394/solr/dv_coll_shard2_replica1/&rows=100&version=2&q=*:*&NOW=1485800532463&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> 958104 INFO (qtp695883925-7518) [ ] 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:33764/solr/dv_coll_shard1_replica1/&rows=100&version=2&q=*:*&NOW=1485800532463&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> 958107 INFO (qtp695883925-7516) [ ] o.a.s.c.S.Request [dv_coll_shard1_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=37
[junit4] 2> 958108 INFO (TEST-DocValuesNotIndexedTest.testGroupingDVOnly-seed#[6E668EC65E6AFB57]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testGroupingDVOnly
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=DocValuesNotIndexedTest -Dtests.method=testGroupingDVOnly -Dtests.seed=6E668EC65E6AFB57 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=und -Dtests.timezone=Africa/Monrovia -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 0.32s J1 | DocValuesNotIndexedTest.testGroupingDVOnly <<<
[junit4] > Throwable #1: java.lang.AssertionError: Unexpected number of elements in the group for intGSF: 5
[junit4] > at __randomizedtesting.SeedInfo.seed([6E668EC65E6AFB57:F5DDE09E1332C909]:0)
[junit4] > at org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingDVOnly(DocValuesNotIndexedTest.java:376)
[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:543)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 958120 INFO (TEST-DocValuesNotIndexedTest.testDistribFaceting-seed#[6E668EC65E6AFB57]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDistribFaceting
[junit4] 2> 958127 INFO (qtp1337149954-7501) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2d8026d7[dv_coll_shard2_replica1] realtime]
[junit4] 2> 958127 INFO (qtp1337149954-7501) [ ] 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:33764/solr/dv_coll_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1557974779185594368)} 0 4
[junit4] 2> 958128 INFO (qtp695883925-7565) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5cf995fc[dv_coll_shard1_replica1] realtime]
[junit4] 2> 958128 INFO (qtp1337149954-7502) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2433868b[dv_coll_shard4_replica1] realtime]
[junit4] 2> 958128 INFO (qtp695883925-7565) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:33764/solr/dv_coll_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1557974779185594368)} 0 4
[junit4] 2> 958128 INFO (qtp1337149954-7502) [ ] 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:33764/solr/dv_coll_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1557974779185594368)} 0 4
[junit4] 2> 958129 INFO (qtp695883925-7514) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5163a587[dv_coll_shard3_replica1] realtime]
[junit4] 2> 958129 INFO (qtp695883925-7514) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1557974779183497216)} 0 7
[junit4] 2> 958133 INFO (qtp1337149954-7506) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 958133 INFO (qtp695883925-7517) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 958133 INFO (qtp695883925-7513) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 958133 INFO (qtp695883925-7517) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@62d9f3
[junit4] 2> 958133 INFO (qtp1337149954-7503) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 958133 INFO (qtp1337149954-7506) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@166a049f
[junit4] 2> 958133 INFO (qtp1337149954-7503) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5ea58642
[junit4] 2> 958133 INFO (qtp695883925-7513) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@40e26726
[junit4] 2> 958140 INFO (qtp1337149954-7506) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1fde0c82[dv_coll_shard4_replica1] main]
[junit4] 2> 958140 INFO (qtp1337149954-7506) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958140 INFO (searcherExecutor-3262-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard4_replica1] Registered new searcher Searcher@1fde0c82[dv_coll_shard4_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 958141 INFO (qtp695883925-7513) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@48cd247f[dv_coll_shard1_replica1] main]
[junit4] 2> 958142 INFO (searcherExecutor-3256-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard1_replica1] Registered new searcher Searcher@48cd247f[dv_coll_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 958142 INFO (qtp695883925-7513) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958142 INFO (qtp1337149954-7503) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@a003f0[dv_coll_shard2_replica1] main]
[junit4] 2> 958142 INFO (qtp1337149954-7503) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958142 INFO (searcherExecutor-3263-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard2_replica1] Registered new searcher Searcher@a003f0[dv_coll_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 958165 INFO (qtp695883925-7513) [ ] 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:43394/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 32
[junit4] 2> 958166 INFO (qtp1337149954-7503) [ ] 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:43394/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 33
[junit4] 2> 958168 INFO (qtp695883925-7517) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2de13d39[dv_coll_shard3_replica1] main]
[junit4] 2> 958168 INFO (qtp695883925-7517) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958168 INFO (searcherExecutor-3281-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] Registered new searcher Searcher@2de13d39[dv_coll_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 958169 INFO (qtp1337149954-7506) [ ] 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:43394/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 36
[junit4] 2> 958176 INFO (qtp695883925-7517) [ ] 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:43394/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 43
[junit4] 2> 958177 INFO (qtp1337149954-7507) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica1] webapp=/solr path=/update params={_stateVer_=dv_coll:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 45
[junit4] 2> 958182 INFO (qtp695883925-7512) [ ] 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 (1557974779243266048)]} 0 2
[junit4] 2> 958185 INFO (qtp1337149954-7598) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 958185 INFO (qtp695883925-7518) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 958185 INFO (qtp1337149954-7598) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 958185 INFO (qtp1337149954-7502) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 958185 INFO (qtp695883925-7513) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 958185 INFO (qtp1337149954-7502) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 958185 INFO (qtp695883925-7513) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 958185 INFO (qtp1337149954-7598) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958185 INFO (qtp695883925-7518) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@40e26726
[junit4] 2> 958185 INFO (qtp1337149954-7598) [ ] 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:33764/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0
[junit4] 2> 958185 INFO (qtp1337149954-7502) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958185 INFO (qtp695883925-7513) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958185 INFO (qtp1337149954-7502) [ ] 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:33764/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0
[junit4] 2> 958186 INFO (qtp695883925-7513) [ ] 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:33764/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0
[junit4] 2> 958236 INFO (qtp695883925-7518) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@44bf7b09[dv_coll_shard1_replica1] main]
[junit4] 2> 958236 INFO (qtp695883925-7518) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958236 INFO (searcherExecutor-3256-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard1_replica1] Registered new searcher Searcher@44bf7b09[dv_coll_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(6.5.0):C1)))}
[junit4] 2> 958236 INFO (qtp695883925-7518) [ ] 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:33764/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 51
[junit4] 2> 958237 INFO (qtp695883925-7565) [ ] 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 53
[junit4] 2> 958243 INFO (qtp695883925-7517) [ ] o.a.s.c.S.Request [dv_coll_shard3_replica1] webapp=/solr path=/select params={df=text&distrib=false&f.dateFieldMulti.facet.limit=160&fl=id&fl=score&shards.purpose=20&f.intField.facet.limit=160&fsv=true&f.longFieldMulti.facet.limit=160&f.boolFieldMulti.facet.limit=160&shard.url=https://127.0.0.1:33764/solr/dv_coll_shard3_replica1/&f.longField.facet.mincount=0&f.boolField.facet.mincount=0&f.dateField.facet.mincount=0&f.doubleField.facet.limit=160&f.doubleFieldMulti.facet.mincount=0&f.floatField.facet.mincount=0&f.dateFieldMulti.facet.mincount=0&f.doubleField.facet.mincount=0&f.boolField.facet.limit=160&f.stringField.facet.mincount=0&f.stringFieldMulti.facet.limit=160&f.boolFieldMulti.facet.mincount=0&f.intField.facet.mincount=0&f.intFieldMulti.facet.mincount=0&f.doubleFieldMulti.facet.limit=160&wt=javabin&facet.field=intField&facet.field=longField&facet.field=doubleField&facet.field=floatField&facet.field=dateField&facet.field=stringField&facet.field=boolField&facet.field=intFieldMulti&facet.field=longFieldMulti&facet.field=doubleFieldMulti&facet.field=floatFieldMulti&facet.field=dateFieldMulti&facet.field=stringFieldMulti&facet.field=boolFieldMulti&_stateVer_=dv_coll:3&f.longFieldMulti.facet.mincount=0&start=0&rows=0&f.dateField.facet.limit=160&version=2&f.stringFieldMulti.facet.mincount=0&q=*:*&f.floatFieldMulti.facet.limit=160&f.longField.facet.limit=160&f.stringField.facet.limit=160&NOW=1485800532633&f.intFieldMulti.facet.limit=160&f.floatFieldMulti.facet.mincount=0&isShard=true&f.floatField.facet.limit=160&facet=true} hits=0 status=0 QTime=2
[junit4] 2> 958243 INFO (qtp1337149954-7503) [ ] o.a.s.c.S.Request [dv_coll_shard4_replica1] webapp=/solr path=/select params={df=text&distrib=false&f.dateFieldMulti.facet.limit=160&fl=id&fl=score&shards.purpose=20&f.intField.facet.limit=160&fsv=true&f.longFieldMulti.facet.limit=160&f.boolFieldMulti.facet.limit=160&shard.url=https://127.0.0.1:43394/solr/dv_coll_shard4_replica1/&f.longField.facet.mincount=0&f.boolField.facet.mincount=0&f.dateField.facet.mincount=0&f.doubleField.facet.limit=160&f.doubleFieldMulti.facet.mincount=0&f.floatField.facet.mincount=0&f.dateFieldMulti.facet.mincount=0&f.doubleField.facet.mincount=0&f.boolField.facet.limit=160&f.stringField.facet.mincount=0&f.stringFieldMulti.facet.limit=160&f.boolFieldMulti.facet.mincount=0&f.intField.facet.mincount=0&f.intFieldMulti.facet.mincount=0&f.doubleFieldMulti.facet.limit=160&wt=javabin&facet.field=intField&facet.field=longField&facet.field=doubleField&facet.field=floatField&facet.field=dateField&facet.field=stringField&facet.field=boolField&facet.field=intFieldMulti&facet.field=longFieldMulti&facet.field=doubleFieldMulti&facet.field=floatFieldMulti&facet.field=dateFieldMulti&facet.field=stringFieldMulti&facet.field=boolFieldMulti&_stateVer_=dv_coll:3&f.longFieldMulti.facet.mincount=0&start=0&rows=0&f.dateField.facet.limit=160&version=2&f.stringFieldMulti.facet.mincount=0&q=*:*&f.floatFieldMulti.facet.limit=160&f.longField.facet.limit=160&f.stringField.facet.limit=160&NOW=1485800532633&f.intFieldMulti.facet.limit=160&f.floatFieldMulti.facet.mincount=0&isShard=true&f.floatField.facet.limit=160&facet=true} hits=0 status=0 QTime=2
[junit4] 2> 958243 INFO (qtp1337149954-7504) [ ] o.a.s.c.S.Request [dv_coll_shard2_replica1] webapp=/solr path=/select params={df=text&distrib=false&f.dateFieldMulti.facet.limit=160&fl=id&fl=score&shards.purpose=20&f.intField.facet.limit=160&fsv=true&f.longFieldMulti.facet.limit=160&f.boolFieldMulti.facet.limit=160&shard.url=https://127.0.0.1:43394/solr/dv_coll_shard2_replica1/&f.longField.facet.mincount=0&f.boolField.facet.mincount=0&f.dateField.facet.mincount=0&f.doubleField.facet.limit=160&f.doubleFieldMulti.facet.mincount=0&f.floatField.facet.mincount=0&f.dateFieldMulti.facet.mincount=0&f.doubleField.facet.mincount=0&f.boolField.facet.limit=160&f.stringField.facet.mincount=0&f.stringFieldMulti.facet.limit=160&f.boolFieldMulti.facet.mincount=0&f.intField.facet.mincount=0&f.intFieldMulti.facet.mincount=0&f.doubleFieldMulti.facet.limit=160&wt=javabin&facet.field=intField&facet.field=longField&facet.field=doubleField&facet.field=floatField&facet.field=dateField&facet.field=stringField&facet.field=boolField&facet.field=intFieldMulti&facet.field=longFieldMulti&facet.field=doubleFieldMulti&facet.field=floatFieldMulti&facet.field=dateFieldMulti&facet.field=stringFieldMulti&facet.field=boolFieldMulti&_stateVer_=dv_coll:3&f.longFieldMulti.facet.mincount=0&start=0&rows=0&f.dateField.facet.limit=160&version=2&f.stringFieldMulti.facet.mincount=0&q=*:*&f.floatFieldMulti.facet.limit=160&f.longField.facet.limit=160&f.stringField.facet.limit=160&NOW=1485800532633&f.intFieldMulti.facet.limit=160&f.floatFieldMulti.facet.mincount=0&isShard=true&f.floatField.facet.limit=160&facet=true} hits=0 status=0 QTime=2
[junit4] 2> 958247 INFO (qtp695883925-7512) [ ] o.a.s.c.S.Request [dv_coll_shard1_replica1] webapp=/solr path=/select params={df=text&distrib=false&f.dateFieldMulti.facet.limit=160&fl=id&fl=score&shards.purpose=20&f.intField.facet.limit=160&fsv=true&f.longFieldMulti.facet.limit=160&f.boolFieldMulti.facet.limit=160&shard.url=https://127.0.0.1:33764/solr/dv_coll_shard1_replica1/&f.longField.facet.mincount=0&f.boolField.facet.mincount=0&f.dateField.facet.mincount=0&f.doubleField.facet.limit=160&f.doubleFieldMulti.facet.mincount=0&f.floatField.facet.mincount=0&f.dateFieldMulti.facet.mincount=0&f.doubleField.facet.mincount=0&f.boolField.facet.limit=160&f.stringField.facet.mincount=0&f.stringFieldMulti.facet.limit=160&f.boolFieldMulti.facet.mincount=0&f.intField.facet.mincount=0&f.intFieldMulti.facet.mincount=0&f.doubleFieldMulti.facet.limit=160&wt=javabin&facet.field=intField&facet.field=longField&facet.field=doubleField&facet.field=floatField&facet.field=dateField&facet.field=stringField&facet.field=boolField&facet.field=intFieldMulti&facet.field=longFieldMulti&facet.field=doubleFieldMulti&facet.field=floatFieldMulti&facet.field=dateFieldMulti&facet.field=stringFieldMulti&facet.field=boolFieldMulti&_stateVer_=dv_coll:3&f.longFieldMulti.facet.mincount=0&start=0&rows=0&f.dateField.facet.limit=160&version=2&f.stringFieldMulti.facet.mincount=0&q=*:*&f.floatFieldMulti.facet.limit=160&f.longField.facet.limit=160&f.stringField.facet.limit=160&NOW=1485800532633&f.intFieldMulti.facet.limit=160&f.floatFieldMulti.facet.mincount=0&isShard=true&f.floatField.facet.limit=160&facet=true} hits=1 status=0 QTime=6
[junit4] 2> 958248 INFO (qtp1337149954-7508) [ ] o.a.s.c.S.Request [dv_coll_shard2_replica1] webapp=/solr path=/select params={q=*:*&facet.field=intField&facet.field=longField&facet.field=doubleField&facet.field=floatField&facet.field=dateField&facet.field=stringField&facet.field=boolField&facet.field=intFieldMulti&facet.field=longFieldMulti&facet.field=doubleFieldMulti&facet.field=floatFieldMulti&facet.field=dateFieldMulti&facet.field=stringFieldMulti&facet.field=boolFieldMulti&_stateVer_=dv_coll:3&rows=0&facet=true&wt=javabin&version=2} hits=1 status=0 QTime=9
[junit4] 2> 958249 INFO (TEST-DocValuesNotIndexedTest.testDistribFaceting-seed#[6E668EC65E6AFB57]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDistribFaceting
[junit4] 2> 958261 INFO (TEST-DocValuesNotIndexedTest.testGroupingDocAbsent-seed#[6E668EC65E6AFB57]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testGroupingDocAbsent
[junit4] 2> 958265 INFO (qtp1337149954-7502) [ ] 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:33764/solr/dv_coll_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1557974779332395008)} 0 0
[junit4] 2> 958266 INFO (qtp695883925-7513) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@556df737[dv_coll_shard1_replica1] realtime]
[junit4] 2> 958266 INFO (qtp695883925-7513) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:33764/solr/dv_coll_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1557974779332395008)} 0 1
[junit4] 2> 958266 INFO (qtp1337149954-7507) [ ] 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:33764/solr/dv_coll_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1557974779332395008)} 0 1
[junit4] 2> 958266 INFO (qtp695883925-7514) [ ] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1557974779331346432)} 0 3
[junit4] 2> 958269 INFO (qtp1337149954-7503) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 958269 INFO (qtp695883925-7565) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 958271 INFO (qtp1337149954-7503) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 958269 INFO (qtp1337149954-7504) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 958269 INFO (qtp695883925-7516) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 958271 INFO (qtp1337149954-7504) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 958271 INFO (qtp695883925-7565) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@40e26726
[junit4] 2> 958271 INFO (qtp1337149954-7503) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958271 INFO (qtp695883925-7516) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 958271 INFO (qtp1337149954-7504) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958271 INFO (qtp1337149954-7503) [ ] 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:33764/solr/dv_coll_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1
[junit4] 2> 958271 INFO (qtp1337149954-7504) [ ] 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:33764/solr/dv_coll_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 2
[junit4] 2> 958271 INFO (qtp695883925-7516) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958271 INFO (qtp695883925-7516) [ ] 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:33764/solr/dv_coll_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 2
[junit4] 2> 958274 INFO (qtp695883925-7565) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@70762c0f[dv_coll_shard1_replica1] main]
[junit4] 2> 958275 INFO (qtp695883925-7565) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 958275 INFO (searcherExecutor-3256-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard1_replica1] Registered new searcher Searcher@70762c0f[dv_coll_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 958284 INFO (qtp695883925-7565) [ ] 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:33764/solr/dv_coll_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 14
[junit4] 2> 958284 INFO (qtp695883925-7518) [ ] 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 16
[junit4] 2> 958289 INFO (qtp1337149954-7506) [ ] 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 (1557974779355463680)]} 0 3
[junit4] 2> 958289 INFO (qtp695883925-7517) [ ] 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 (1557974779355463680)]} 0 3
[junit4] 2> 958289 INFO (qtp695883925-7511) [ ] 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 (15
[...truncated too long message...]
ime=0
[junit4] 2> 958778 INFO (qtp1337149954-7507) [ ] o.a.s.c.S.Request [dv_coll_shard4_replica1] webapp=/solr path=/select params={q=*:*&_stateVer_=dv_coll:3&sort=boolGSL+desc,id+asc&rows=100&wt=javabin&version=2} hits=4 status=0 QTime=5
[junit4] 2> 958779 INFO (TEST-DocValuesNotIndexedTest.testGroupingSorting-seed#[6E668EC65E6AFB57]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testGroupingSorting
[junit4] 2> 958781 INFO (jetty-launcher-1270-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@56aba2bb{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 958781 INFO (jetty-launcher-1270-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@77f68f37{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 958781 INFO (jetty-launcher-1270-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=95441714
[junit4] 2> 958781 INFO (jetty-launcher-1270-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=187727887
[junit4] 2> 958782 INFO (coreCloseExecutor-3285-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard4_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@7972e869
[junit4] 2> 958782 INFO (coreCloseExecutor-3286-thread-1) [ ] o.a.s.c.SolrCore [dv_coll_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@5c24f1fd
[junit4] 2> 958783 INFO (coreCloseExecutor-3285-thread-2) [ ] o.a.s.c.SolrCore [dv_coll_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@14507b76
[junit4] 2> 958783 INFO (zkCallback-1282-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> 958783 INFO (zkCallback-1277-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> 958784 INFO (coreCloseExecutor-3286-thread-2) [ ] o.a.s.c.SolrCore [dv_coll_shard3_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@3843061c
[junit4] 2> 958785 INFO (coreCloseExecutor-3285-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.dv_coll.shard4.replica1
[junit4] 2> 958787 INFO (coreCloseExecutor-3286-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.dv_coll.shard1.replica1
[junit4] 2> 958788 INFO (coreCloseExecutor-3285-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.dv_coll.shard2.replica1
[junit4] 2> 958789 INFO (coreCloseExecutor-3286-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.dv_coll.shard3.replica1
[junit4] 2> 958790 INFO (jetty-launcher-1270-thread-1) [ ] o.a.s.c.Overseer Overseer (id=97373423488925700-127.0.0.1:43394_solr-n_0000000000) closing
[junit4] 2> 958790 INFO (OverseerStateUpdate-97373423488925700-127.0.0.1:43394_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:43394_solr
[junit4] 2> 958791 INFO (zkCallback-1277-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 958791 WARN (zkCallback-1277-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> 958791 INFO (jetty-launcher-1270-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 958791 INFO (jetty-launcher-1270-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1f762ef4{/solr,null,UNAVAILABLE}
[junit4] 2> 960291 WARN (zkCallback-1282-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 960291 INFO (jetty-launcher-1270-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 960291 INFO (jetty-launcher-1270-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@29432ab0{/solr,null,UNAVAILABLE}
[junit4] 2> 960292 INFO (SUITE-DocValuesNotIndexedTest-seed#[6E668EC65E6AFB57]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34831 34831
[junit4] 2> 960317 INFO (Thread-1925) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34831 34831
[junit4] 2> 960318 WARN (Thread-1925) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 6 /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> 7 /solr/overseer/queue
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2> 3 /solr/overseer/queue-work
[junit4] 2> 3 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> 960318 INFO (SUITE-DocValuesNotIndexedTest-seed#[6E668EC65E6AFB57]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_6E668EC65E6AFB57-001
[junit4] 2> Jan 30, 2017 6:22:14 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {_version_=Lucene50(blocksize=128), id=PostingsFormat(name=Memory doPackFST= true)}, docValues:{floatField=DocValuesFormat(name=Direct), doubleField=DocValuesFormat(name=Lucene54), intFieldMulti=DocValuesFormat(name=Direct), boolFieldMulti=DocValuesFormat(name=Lucene54), longFieldMulti=DocValuesFormat(name=Lucene54), floatGSL=DocValuesFormat(name=Memory), intField=DocValuesFormat(name=Lucene54), boolField=DocValuesFormat(name=Memory), stringFieldMulti=DocValuesFormat(name=Memory), dateFieldMulti=DocValuesFormat(name=Lucene54), longGSF=DocValuesFormat(name=Direct), doubleFieldMulti=DocValuesFormat(name=Memory), stringGSL=DocValuesFormat(name=Lucene54), doubleGSF=DocValuesFormat(name=Lucene54), doubleGSL=DocValuesFormat(name=Lucene54), stringGSF=DocValuesFormat(name=Lucene54), intGSL=DocValuesFormat(name=Lucene54), longField=DocValuesFormat(name=Direct), dateField=DocValuesFormat(name=Memory), dateGSF=DocValuesFormat(name=Memory), boolGSF=DocValuesFormat(name=Memory), longGSL=DocValuesFormat(name=Memory), boolGSL=DocValuesFormat(name=Direct), floatFieldMulti=DocValuesFormat(name=Lucene54), floatGSF=DocValuesFormat(name=Direct), dateGSL=DocValuesFormat(name=Direct), intGSF=DocValuesFormat(name=Lucene54), stringField=DocValuesFormat(name=Lucene54)}, maxPointsInLeafNode=1454, maxMBSortInHeap=5.979887017144368, sim=RandomSimilarity(queryNorm=true,coord=yes): {}, locale=und, timezone=Africa/Monrovia
[junit4] 2> NOTE: Linux 4.4.0-53-generic amd64/Oracle Corporation 9-ea (64-bit)/cpus=12,threads=1,free=109168840,total=509149184
[junit4] 2> NOTE: All tests run in this JVM: [TestDFISimilarityFactory, DistributedFacetPivotLargeTest, TestCryptoKeys, HdfsDirectoryTest, DistributedDebugComponentTest, CSVRequestHandlerTest, DirectSolrSpellCheckerTest, TestRestManager, CloudMLTQParserTest, TestCloudSchemaless, BadCopyFieldTest, AnalysisErrorHandlingTest, CollectionsAPIAsyncDistributedZkTest, TestHashPartitioner, TestCoreContainer, AliasIntegrationTest, TestScoreJoinQPNoScore, SolrMetricManagerTest, TestRandomFlRTGCloud, TermVectorComponentTest, ShardRoutingTest, TestStandardQParsers, TestRTGBase, PreAnalyzedUpdateProcessorTest, PeerSyncWithIndexFingerprintCachingTest, PeerSyncReplicationTest, DistributedIntervalFacetingTest, TestReRankQParserPlugin, TestSimpleTrackingShardHandler, SolrIndexConfigTest, ZkSolrClientTest, SpatialFilterTest, MergeStrategyTest, DirectoryFactoryTest, TestGraphMLResponseWriter, ConfigSetsAPITest, TestLRUStatsCache, DateRangeFieldTest, OverriddenZkACLAndCredentialsProvidersTest, TestSolrConfigHandler, TestLRUCache, TestReplicaProperties, RollingRestartTest, TestFieldCacheSort, DistributedMLTComponentTest, SearchHandlerTest, HdfsThreadLeakTest, AnalyticsMergeStrategyTest, DeleteNodeTest, TestSSLRandomization, TestTolerantUpdateProcessorCloud, JavabinLoaderTest, SpellCheckComponentTest, TestFastOutputStream, TestQuerySenderListener, ZkStateReaderTest, TestCorePropertiesReload, TestSQLHandler, TestReplicationHandlerBackup, DistributedQueryComponentOptimizationTest, HLLUtilTest, TermsComponentTest, HdfsCollectionsAPIDistributedZkTest, TestSolrCloudSnapshots, ClassificationUpdateProcessorIntegrationTest, TestCharFilters, CollectionReloadTest, URLClassifyProcessorTest, DistanceFunctionTest, TestManagedSchemaAPI, TestDynamicFieldResource, TestSha256AuthenticationProvider, TestSchemalessBufferedUpdates, TestCloudRecovery, ClusterStateUpdateTest, TestBlobHandler, DateMathParserTest, TestWordDelimiterFilterFactory, SolrGangliaReporterTest, CoreMergeIndexesAdminHandlerTest, TestImplicitCoreProperties, TestCursorMarkWithoutUniqueKey, BlockJoinFacetRandomTest, SolrIndexSplitterTest, DocValuesNotIndexedTest]
[junit4] Completed [289/681 (1!)] on J1 in 5.92s, 4 tests, 1 failure <<< FAILURES!
[...truncated 52785 lines...]