Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-MacOSX/675/
Java: 64bit/jdk1.8.0 -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([FF059E9D84C926FE:64BEF0C5C99114A0]:0)
at org.junit.Assert.fail(Assert.java:93)
at
org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingDVOnly(DocValuesNotIndexedTest.java:376)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 12309 lines...]
[junit4] Suite: org.apache.solr.cloud.DocValuesNotIndexedTest
[junit4] 2> Creating dataDir:
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/init-core-data-001
[junit4] 2> 2483593 INFO
(SUITE-DocValuesNotIndexedTest-seed#[FF059E9D84C926FE]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via:
@org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
w/ MAC_OS_X supressed clientAuth
[junit4] 2> 2483595 INFO
(SUITE-DocValuesNotIndexedTest-seed#[FF059E9D84C926FE]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001
[junit4] 2> 2483595 INFO
(SUITE-DocValuesNotIndexedTest-seed#[FF059E9D84C926FE]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2483595 INFO (Thread-3372) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2483595 INFO (Thread-3372) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 2483697 INFO
(SUITE-DocValuesNotIndexedTest-seed#[FF059E9D84C926FE]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:60288
[junit4] 2> 2483720 INFO (jetty-launcher-3461-thread-1) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2483720 INFO (jetty-launcher-3461-thread-2) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2483723 INFO (jetty-launcher-3461-thread-2) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@41ed1014{/solr,null,AVAILABLE}
[junit4] 2> 2483724 INFO (jetty-launcher-3461-thread-2) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@e104772{HTTP/1.1,[http/1.1]}{127.0.0.1:60290}
[junit4] 2> 2483724 INFO (jetty-launcher-3461-thread-2) [ ]
o.e.j.s.Server Started @2489107ms
[junit4] 2> 2483725 INFO (jetty-launcher-3461-thread-2) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=60290}
[junit4] 2> 2483725 INFO (jetty-launcher-3461-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@405472a2{/solr,null,AVAILABLE}
[junit4] 2> 2483725 ERROR (jetty-launcher-3461-thread-2) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 2483726 INFO (jetty-launcher-3461-thread-1) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@2797e3cc{HTTP/1.1,[http/1.1]}{127.0.0.1:60291}
[junit4] 2> 2483726 INFO (jetty-launcher-3461-thread-1) [ ]
o.e.j.s.Server Started @2489109ms
[junit4] 2> 2483726 INFO (jetty-launcher-3461-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=60291}
[junit4] 2> 2483726 INFO (jetty-launcher-3461-thread-2) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
6.5.0
[junit4] 2> 2483726 INFO (jetty-launcher-3461-thread-2) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2483726 ERROR (jetty-launcher-3461-thread-1) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 2483726 INFO (jetty-launcher-3461-thread-2) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2483727 INFO (jetty-launcher-3461-thread-2) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-02-01T09:30:15.870Z
[junit4] 2> 2483727 INFO (jetty-launcher-3461-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
6.5.0
[junit4] 2> 2483727 INFO (jetty-launcher-3461-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2483727 INFO (jetty-launcher-3461-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2483727 INFO (jetty-launcher-3461-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-02-01T09:30:15.870Z
[junit4] 2> 2483731 INFO (jetty-launcher-3461-thread-2) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2483731 INFO (jetty-launcher-3461-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2483745 INFO (jetty-launcher-3461-thread-2) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2483745 INFO (jetty-launcher-3461-thread-1) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2483745 INFO (jetty-launcher-3461-thread-2) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60288/solr
[junit4] 2> 2483746 INFO (jetty-launcher-3461-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60288/solr
[junit4] 2> 2483797 INFO (jetty-launcher-3461-thread-2)
[n:127.0.0.1:60290_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:60290_solr
[junit4] 2> 2483798 INFO (jetty-launcher-3461-thread-1)
[n:127.0.0.1:60291_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:60291_solr
[junit4] 2> 2483800 INFO (jetty-launcher-3461-thread-2)
[n:127.0.0.1:60290_solr ] o.a.s.c.Overseer Overseer
(id=97382656622002181-127.0.0.1:60290_solr-n_0000000000) starting
[junit4] 2> 2483802 INFO
(zkCallback-3471-thread-1-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 2483802 INFO
(zkCallback-3472-thread-1-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 2483817 INFO (jetty-launcher-3461-thread-2)
[n:127.0.0.1:60290_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:60290_solr
[junit4] 2> 2483820 INFO
(zkCallback-3472-thread-1-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 2483820 INFO
(zkCallback-3471-thread-1-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 2483867 INFO (jetty-launcher-3461-thread-2)
[n:127.0.0.1:60290_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node2/.
[junit4] 2> 2483902 INFO (jetty-launcher-3461-thread-1)
[n:127.0.0.1:60291_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node1/.
[junit4] 2> 2485539 INFO
(SUITE-DocValuesNotIndexedTest-seed#[FF059E9D84C926FE]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2485541 INFO
(SUITE-DocValuesNotIndexedTest-seed#[FF059E9D84C926FE]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:60288/solr ready
[junit4] 2> 2485553 INFO (qtp1772586296-17600) [n:127.0.0.1:60291_solr
] 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> 2485556 INFO
(OverseerThreadFactory-8032-thread-1-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] o.a.s.c.CreateCollectionCmd Create collection
dv_coll
[junit4] 2> 2485670 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
] 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> 2485671 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
] 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> 2485673 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
] 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> 2485673 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
] 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> 2485793 INFO
(zkCallback-3471-thread-1-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] 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> 2485794 INFO
(zkCallback-3472-thread-1-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] 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> 2486695 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.c.SolrConfig Using Lucene
MatchVersion: 6.5.0
[junit4] 2> 2486696 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.c.SolrConfig Using Lucene
MatchVersion: 6.5.0
[junit4] 2> 2486697 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.c.SolrConfig Using Lucene
MatchVersion: 6.5.0
[junit4] 2> 2486730 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.c.SolrConfig Using Lucene
MatchVersion: 6.5.0
[junit4] 2> 2486732 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.s.IndexSchema
[dv_coll_shard1_replica1] Schema name=minimal
[junit4] 2> 2486733 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.s.IndexSchema
[dv_coll_shard2_replica1] Schema name=minimal
[junit4] 2> 2486739 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.s.IndexSchema
[dv_coll_shard4_replica1] Schema name=minimal
[junit4] 2> 2486739 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.s.IndexSchema Loaded
schema minimal/1.1 with uniqueid field id
[junit4] 2> 2486739 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.s.IndexSchema Loaded
schema minimal/1.1 with uniqueid field id
[junit4] 2> 2486742 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.s.IndexSchema Loaded
schema minimal/1.1 with uniqueid field id
[junit4] 2> 2486743 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.c.CoreContainer Creating
SolrCore 'dv_coll_shard2_replica1' using configuration from collection dv_coll
[junit4] 2> 2486743 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.c.CoreContainer Creating
SolrCore 'dv_coll_shard1_replica1' using configuration from collection dv_coll
[junit4] 2> 2486743 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.c.SolrCore
[[dv_coll_shard2_replica1] ] Opening new SolrCore at
[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node2/dv_coll_shard2_replica1],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node2/./dv_coll_shard2_replica1/data/]
[junit4] 2> 2486744 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.c.SolrCore
[[dv_coll_shard1_replica1] ] Opening new SolrCore at
[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node1/dv_coll_shard1_replica1],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node1/./dv_coll_shard1_replica1/data/]
[junit4] 2> 2486746 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.c.CoreContainer Creating
SolrCore 'dv_coll_shard4_replica1' using configuration from collection dv_coll
[junit4] 2> 2486746 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.c.SolrCore
[[dv_coll_shard4_replica1] ] Opening new SolrCore at
[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node2/dv_coll_shard4_replica1],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node2/./dv_coll_shard4_replica1/data/]
[junit4] 2> 2486747 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.s.IndexSchema
[dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 2486751 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.s.IndexSchema Loaded
schema minimal/1.1 with uniqueid field id
[junit4] 2> 2486752 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.c.CoreContainer Creating
SolrCore 'dv_coll_shard3_replica1' using configuration from collection dv_coll
[junit4] 2> 2486753 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.c.SolrCore
[[dv_coll_shard3_replica1] ] Opening new SolrCore at
[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node1/dv_coll_shard3_replica1],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node1/./dv_coll_shard3_replica1/data/]
[junit4] 2> 2486790 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.u.UpdateHandler Using
UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2486790 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.u.UpdateLog Initializing
UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2486790 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.u.UpdateHandler Using
UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2486790 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.u.UpdateLog Initializing
UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2486792 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.u.CommitTracker Hard
AutoCommit: disabled
[junit4] 2> 2486792 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.u.CommitTracker Soft
AutoCommit: disabled
[junit4] 2> 2486793 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.u.UpdateHandler Using
UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2486794 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.u.UpdateLog Initializing
UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2486794 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.u.CommitTracker Hard
AutoCommit: disabled
[junit4] 2> 2486794 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.u.CommitTracker Soft
AutoCommit: disabled
[junit4] 2> 2486797 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.u.CommitTracker Hard
AutoCommit: disabled
[junit4] 2> 2486797 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.u.CommitTracker Soft
AutoCommit: disabled
[junit4] 2> 2486798 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.u.UpdateHandler Using
UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2486798 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.u.UpdateLog Initializing
UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2486799 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.s.SolrIndexSearcher
Opening [Searcher@20c7449d[dv_coll_shard4_replica1] main]
[junit4] 2> 2486800 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.u.CommitTracker Hard
AutoCommit: disabled
[junit4] 2> 2486800 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.u.CommitTracker Soft
AutoCommit: disabled
[junit4] 2> 2486800 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.s.SolrIndexSearcher
Opening [Searcher@12b2f7d9[dv_coll_shard1_replica1] main]
[junit4] 2> 2486802 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.s.SolrIndexSearcher
Opening [Searcher@67489577[dv_coll_shard2_replica1] main]
[junit4] 2> 2486802 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.r.ManagedResourceStorage
Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2486803 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.r.ManagedResourceStorage
Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2486803 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.r.ManagedResourceStorage
Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2486803 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.s.ZkIndexSchemaReader
Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2486804 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.r.ManagedResourceStorage
Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2486804 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.s.ZkIndexSchemaReader
Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2486805 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.r.ManagedResourceStorage
Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2486805 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.s.ZkIndexSchemaReader
Current schema version 0 is already the latest
[junit4] 2> 2486805 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.h.ReplicationHandler
Commits will be reserved for 10000
[junit4] 2> 2486805 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.u.UpdateLog Could not find
max version in index or recent updates, using new clock 1558122509314818048
[junit4] 2> 2486805 INFO
(searcherExecutor-8039-thread-1-processing-n:127.0.0.1:60290_solr
x:dv_coll_shard4_replica1 s:shard4 c:dv_coll) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 x:dv_coll_shard4_replica1] o.a.s.c.SolrCore [dv_coll_shard4_replica1]
Registered new searcher Searcher@20c7449d[dv_coll_shard4_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2486806 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.r.ManagedResourceStorage
Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2486806 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.s.ZkIndexSchemaReader
Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2486806 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.s.ZkIndexSchemaReader
Current schema version 0 is already the latest
[junit4] 2> 2486806 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.h.ReplicationHandler
Commits will be reserved for 10000
[junit4] 2> 2486807 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.u.UpdateLog Could not find
max version in index or recent updates, using new clock 1558122509316915200
[junit4] 2> 2486807 INFO
(searcherExecutor-8038-thread-1-processing-n:127.0.0.1:60291_solr
x:dv_coll_shard1_replica1 s:shard1 c:dv_coll) [n:127.0.0.1:60291_solr c:dv_coll
s:shard1 x:dv_coll_shard1_replica1] o.a.s.c.SolrCore [dv_coll_shard1_replica1]
Registered new searcher Searcher@12b2f7d9[dv_coll_shard1_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2486810 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.s.ZkIndexSchemaReader
Current schema version 0 is already the latest
[junit4] 2> 2486810 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.h.ReplicationHandler
Commits will be reserved for 10000
[junit4] 2> 2486810 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.u.UpdateLog Could not find
max version in index or recent updates, using new clock 1558122509320060928
[junit4] 2> 2486810 INFO
(searcherExecutor-8037-thread-1-processing-n:127.0.0.1:60290_solr
x:dv_coll_shard2_replica1 s:shard2 c:dv_coll) [n:127.0.0.1:60290_solr c:dv_coll
s:shard2 x:dv_coll_shard2_replica1] o.a.s.c.SolrCore [dv_coll_shard2_replica1]
Registered new searcher Searcher@67489577[dv_coll_shard2_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2486814 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.s.SolrIndexSearcher
Opening [Searcher@477e2a1[dv_coll_shard3_replica1] main]
[junit4] 2> 2486817 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.r.ManagedResourceStorage
Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2486818 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.r.ManagedResourceStorage
Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2486818 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.s.ZkIndexSchemaReader
Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2486820 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.s.ZkIndexSchemaReader
Current schema version 0 is already the latest
[junit4] 2> 2486820 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.h.ReplicationHandler
Commits will be reserved for 10000
[junit4] 2> 2486821 INFO
(searcherExecutor-8040-thread-1-processing-n:127.0.0.1:60291_solr
x:dv_coll_shard3_replica1 s:shard3 c:dv_coll) [n:127.0.0.1:60291_solr c:dv_coll
s:shard3 x:dv_coll_shard3_replica1] o.a.s.c.SolrCore [dv_coll_shard3_replica1]
Registered new searcher Searcher@477e2a1[dv_coll_shard3_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2486821 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.u.UpdateLog Could not find
max version in index or recent updates, using new clock 1558122509331595264
[junit4] 2> 2486824 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2486824 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2486824 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.c.SyncStrategy Sync
replicas to http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/
[junit4] 2> 2486824 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.c.SyncStrategy Sync
Success - now sync replicas to me
[junit4] 2> 2486824 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.c.SyncStrategy
http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/ has no replicas
[junit4] 2> 2486825 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2486825 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2486825 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.c.SyncStrategy Sync
replicas to http://127.0.0.1:60290/solr/dv_coll_shard4_replica1/
[junit4] 2> 2486825 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.c.SyncStrategy Sync
Success - now sync replicas to me
[junit4] 2> 2486826 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.c.SyncStrategy
http://127.0.0.1:60290/solr/dv_coll_shard4_replica1/ has no replicas
[junit4] 2> 2486827 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2486827 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2486827 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.c.SyncStrategy Sync
replicas to http://127.0.0.1:60290/solr/dv_coll_shard2_replica1/
[junit4] 2> 2486827 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.c.SyncStrategy Sync
Success - now sync replicas to me
[junit4] 2> 2486827 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.c.SyncStrategy
http://127.0.0.1:60290/solr/dv_coll_shard2_replica1/ has no replicas
[junit4] 2> 2486837 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:60290/solr/dv_coll_shard4_replica1/ shard4
[junit4] 2> 2486839 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/ shard1
[junit4] 2> 2486847 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2486847 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2486847 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.c.SyncStrategy Sync
replicas to http://127.0.0.1:60291/solr/dv_coll_shard3_replica1/
[junit4] 2> 2486847 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.c.SyncStrategy Sync
Success - now sync replicas to me
[junit4] 2> 2486847 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.c.SyncStrategy
http://127.0.0.1:60291/solr/dv_coll_shard3_replica1/ has no replicas
[junit4] 2> 2486851 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:60290/solr/dv_coll_shard2_replica1/ shard2
[junit4] 2> 2486861 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:60291/solr/dv_coll_shard3_replica1/ shard3
[junit4] 2> 2486973 INFO
(zkCallback-3471-thread-3-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] 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> 2486973 INFO
(zkCallback-3472-thread-1-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] 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> 2487006 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.c.ZkController I am the
leader, no recovery necessary
[junit4] 2> 2487006 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.c.ZkController I am the
leader, no recovery necessary
[junit4] 2> 2487007 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.c.ZkController I am the
leader, no recovery necessary
[junit4] 2> 2487011 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] 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=1338
[junit4] 2> 2487014 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] 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=1343
[junit4] 2> 2487018 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] 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=1344
[junit4] 2> 2487021 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.c.ZkController I am the
leader, no recovery necessary
[junit4] 2> 2487030 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] 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=1360
[junit4] 2> 2487041 INFO (qtp1772586296-17600) [n:127.0.0.1:60291_solr
] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most
30 seconds. Check all shard replicas
[junit4] 2> 2487135 INFO
(zkCallback-3471-thread-1-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] 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> 2487135 INFO
(zkCallback-3472-thread-1-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] 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> 2487567 INFO
(OverseerCollectionConfigSetProcessor-97382656622002181-127.0.0.1:60290_solr-n_0000000000)
[n:127.0.0.1:60290_solr ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 2488049 INFO (qtp1772586296-17600) [n:127.0.0.1:60291_solr
] 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=2495
[junit4] 2> 2488112 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.s.SchemaManager managed schema loaded . version : 0
[junit4] 2> 2488114 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.s.IndexSchema
[dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 2488116 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.s.IndexSchema
Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2488192 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.c.ZkController
Persisted config data to node /configs/conf1/managed-schema
[junit4] 2> 2488192 INFO
(zkCallback-3472-thread-1-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] 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> 2488192 INFO
(zkCallback-3471-thread-2-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] 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> 2488192 INFO
(zkCallback-3471-thread-1-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] 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> 2488193 INFO
(zkCallback-3472-thread-2-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] 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> 2488193 INFO
(zkCallback-3471-thread-1-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] o.a.s.s.ZkIndexSchemaReader Retrieved schema
version 1 from ZooKeeper
[junit4] 2> 2488194 INFO
(zkCallback-3471-thread-2-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] o.a.s.s.ZkIndexSchemaReader Retrieved schema
version 1 from ZooKeeper
[junit4] 2> 2488196 INFO
(zkCallback-3472-thread-1-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] o.a.s.s.ZkIndexSchemaReader Retrieved schema
version 1 from ZooKeeper
[junit4] 2> 2488198 INFO
(zkCallback-3471-thread-1-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] o.a.s.s.IndexSchema [dv_coll_shard2_replica1]
Schema name=minimal
[junit4] 2> 2488199 INFO
(zkCallback-3471-thread-2-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] o.a.s.s.IndexSchema [dv_coll_shard4_replica1]
Schema name=minimal
[junit4] 2> 2488199 INFO
(zkCallback-3472-thread-1-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] o.a.s.s.IndexSchema [dv_coll_shard1_replica1]
Schema name=minimal
[junit4] 2> 2488255 INFO (Thread-3391) [n:127.0.0.1:60290_solr ]
o.a.s.c.SolrCore config update listener called for core dv_coll_shard4_replica1
[junit4] 2> 2488256 INFO
(zkCallback-3471-thread-1-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with
uniqueid field id
[junit4] 2> 2488257 INFO
(zkCallback-3471-thread-1-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] o.a.s.s.ZkIndexSchemaReader Finished refreshing
schema in 63 ms
[junit4] 2> 2488257 INFO (Thread-3392) [n:127.0.0.1:60291_solr ]
o.a.s.c.SolrCore config update listener called for core dv_coll_shard3_replica1
[junit4] 2> 2488260 INFO
(zkCallback-3472-thread-1-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with
uniqueid field id
[junit4] 2> 2488260 INFO
(zkCallback-3472-thread-1-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] o.a.s.s.ZkIndexSchemaReader Finished refreshing
schema in 63 ms
[junit4] 2> 2488260 INFO
(zkCallback-3471-thread-2-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with
uniqueid field id
[junit4] 2> 2488261 INFO
(zkCallback-3471-thread-2-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] o.a.s.s.ZkIndexSchemaReader Finished refreshing
schema in 66 ms
[junit4] 2> 2488263 INFO (Thread-3391) [n:127.0.0.1:60290_solr ]
o.a.s.c.SolrCore core reload dv_coll_shard4_replica1
[junit4] 2> 2488264 INFO (Thread-3392) [n:127.0.0.1:60291_solr ]
o.a.s.c.SolrCore core reload dv_coll_shard3_replica1
[junit4] 2> 2488278 INFO (Thread-3391) [n:127.0.0.1:60290_solr ]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 2488280 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.c.SolrConfig
Using Lucene MatchVersion: 6.5.0
[junit4] 2> 2488296 INFO (Thread-3391) [n:127.0.0.1:60290_solr ]
o.a.s.s.IndexSchema [dv_coll_shard4_replica1] Schema name=minimal
[junit4] 2> 2488313 INFO (Thread-3391) [n:127.0.0.1:60290_solr ]
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2488317 INFO (Thread-3391) [n:127.0.0.1:60290_solr ]
o.a.s.c.CoreContainer Reloading SolrCore 'dv_coll_shard4_replica1' using
configuration from collection dv_coll
[junit4] 2> 2488329 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.c.SolrCore
[[dv_coll_shard4_replica1] ] Opening new SolrCore at
[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node2/dv_coll_shard4_replica1],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node2/./dv_coll_shard4_replica1/data/]
[junit4] 2> 2488330 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.s.IndexSchema
[dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 2488345 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.u.CommitTracker Hard
AutoCommit: disabled
[junit4] 2> 2488345 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.u.CommitTracker Soft
AutoCommit: disabled
[junit4] 2> 2488346 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.s.SolrIndexSearcher
Opening [Searcher@40569c40[dv_coll_shard4_replica1] main]
[junit4] 2> 2488347 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.s.IndexSchema
Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2488348 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.r.ManagedResourceStorage
Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2488349 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.c.CoreContainer Reloading SolrCore 'dv_coll_shard3_replica1' using
configuration from collection dv_coll
[junit4] 2> 2488349 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.r.ManagedResourceStorage
Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2488349 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.s.ZkIndexSchemaReader
Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2488350 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.c.SolrCore
[[dv_coll_shard3_replica1] ] Opening new SolrCore at
[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node1/dv_coll_shard3_replica1],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node1/./dv_coll_shard3_replica1/data/]
[junit4] 2> 2488351 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.s.ZkIndexSchemaReader
Current schema version 1 is already the latest
[junit4] 2> 2488351 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.h.ReplicationHandler
Commits will be reserved for 10000
[junit4] 2> 2488351 INFO
(searcherExecutor-8057-thread-1-processing-n:127.0.0.1:60290_solr
x:dv_coll_shard4_replica1 s:shard4 c:dv_coll r:core_node3)
[n:127.0.0.1:60290_solr c:dv_coll s:shard4 r:core_node3
x:dv_coll_shard4_replica1] o.a.s.c.SolrCore [dv_coll_shard4_replica1]
Registered new searcher Searcher@40569c40[dv_coll_shard4_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2488351 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.u.UpdateLog Could not
find max version in index or recent updates, using new clock 1558122510935916544
[junit4] 2> 2488359 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.u.DefaultSolrCoreState
New IndexWriter is ready to be used.
[junit4] 2> 2488360 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.s.SolrIndexSearcher
Opening [Searcher@6d5986b8[dv_coll_shard4_replica1] main]
[junit4] 2> 2488360 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.c.SolrCore
[dv_coll_shard4_replica1] CLOSING SolrCore
org.apache.solr.core.SolrCore@506e5174
[junit4] 2> 2488360 INFO
(searcherExecutor-8057-thread-1-processing-n:127.0.0.1:60290_solr
x:dv_coll_shard4_replica1 s:shard4 c:dv_coll r:core_node3)
[n:127.0.0.1:60290_solr c:dv_coll s:shard4 r:core_node3
x:dv_coll_shard4_replica1] o.a.s.c.SolrCore [dv_coll_shard4_replica1]
Registered new searcher Searcher@6d5986b8[dv_coll_shard4_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2488361 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.m.SolrMetricManager
Closing metric reporters for: solr.core.dv_coll.shard4.replica1
[junit4] 2> 2488361 INFO (Thread-3391) [n:127.0.0.1:60290_solr c:dv_coll
s:shard4 r:core_node3 x:dv_coll_shard4_replica1] o.a.s.c.SolrCore config update
listener called for core dv_coll_shard2_replica1
[junit4] 2> 2488373 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2488374 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2488374 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@499cf7c3[dv_coll_shard3_replica1]
main]
[junit4] 2> 2488376 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 2488377 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2488377 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at
/configs/conf1/managed-schema
[junit4] 2> 2488378 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.s.ZkIndexSchemaReader Current schema version 1 is already the latest
[junit4] 2> 2488379 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2488379 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.u.UpdateLog
Could not find max version in index or recent updates, using new clock
1558122510965276672
[junit4] 2> 2488379 INFO
(searcherExecutor-8061-thread-1-processing-n:127.0.0.1:60291_solr
x:dv_coll_shard3_replica1 s:shard3 c:dv_coll r:core_node1)
[n:127.0.0.1:60291_solr c:dv_coll s:shard3 r:core_node1
x:dv_coll_shard3_replica1] o.a.s.c.SolrCore [dv_coll_shard3_replica1]
Registered new searcher Searcher@499cf7c3[dv_coll_shard3_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2488383 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 2488383 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@3c61a7b[dv_coll_shard3_replica1]
main]
[junit4] 2> 2488383 INFO
(searcherExecutor-8061-thread-1-processing-n:127.0.0.1:60291_solr
x:dv_coll_shard3_replica1 s:shard3 c:dv_coll r:core_node1)
[n:127.0.0.1:60291_solr c:dv_coll s:shard3 r:core_node1
x:dv_coll_shard3_replica1] o.a.s.c.SolrCore [dv_coll_shard3_replica1]
Registered new searcher Searcher@3c61a7b[dv_coll_shard3_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2488385 INFO
(zkCallback-3472-thread-2-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] o.a.s.s.ZkIndexSchemaReader Retrieved schema
version 1 from ZooKeeper
[junit4] 2> 2488388 INFO
(zkCallback-3472-thread-2-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] o.a.s.s.IndexSchema [dv_coll_shard3_replica1]
Schema name=minimal
[junit4] 2> 2488394 INFO
(zkCallback-3472-thread-2-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with
uniqueid field id
[junit4] 2> 2488394 INFO
(zkCallback-3472-thread-2-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] o.a.s.s.ZkIndexSchemaReader Finished refreshing
schema in 9 ms
[junit4] 2> 2488395 INFO (Thread-3392) [n:127.0.0.1:60291_solr ]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 2488397 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
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> 2488409 INFO (qtp1652600308-17596) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1] 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> 2488409 INFO (qtp1652600308-17597) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1] 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> 2488411 INFO (Thread-3392) [n:127.0.0.1:60291_solr ]
o.a.s.s.IndexSchema [dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 2488412 INFO (qtp1772586296-17606) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1] 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> 2488413 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.s.ManagedIndexSchema Took 28.0ms for 3 replicas to apply schema update
version 1 for collection dv_coll
[junit4] 2> 2488414 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.c.S.Request
[dv_coll_shard3_replica1] webapp=/solr path=/schema
params={wt=javabin&version=2} status=0 QTime=311
[junit4] 2> 2488414 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.c.SolrCore
[dv_coll_shard3_replica1] CLOSING SolrCore
org.apache.solr.core.SolrCore@440632ec
[junit4] 2> 2488414 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.dv_coll.shard3.replica1
[junit4] 2> 2488528 INFO (Thread-3392) [n:127.0.0.1:60291_solr ]
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2488532 INFO (Thread-3392) [n:127.0.0.1:60291_solr ]
o.a.s.c.CoreContainer Reloading SolrCore 'dv_coll_shard3_replica1' using
configuration from collection dv_coll
[junit4] 2> 2488534 INFO (Thread-3392) [n:127.0.0.1:60291_solr c:dv_coll
s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.c.SolrCore
[[dv_coll_shard3_replica1] ] Opening new SolrCore at
[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node1/dv_coll_shard3_replica1],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001/tempDir-001/node1/./dv_coll_shard3_replica1/data/]
[junit4] 2> 2488567 INFO
(TEST-DocValuesNotIndexedTest.testGroupingDVOnly-seed#[FF059E9D84C926FE]) [
] o.a.s.SolrTestCaseJ4 ###Starting testGroupingDVOnly
[junit4] 2> 2488580 INFO (Thread-3392) [n:127.0.0.1:60291_solr c:dv_coll
s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.u.CommitTracker Hard
AutoCommit: disabled
[junit4] 2> 2488580 INFO (Thread-3392) [n:127.0.0.1:60291_solr c:dv_coll
s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.u.CommitTracker Soft
AutoCommit: disabled
[junit4] 2> 2488587 INFO (qtp1652600308-17590) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1]
o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard4_replica1] webapp=/solr
path=/update
params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:*
(-1558122511179186176)} 0 3
[junit4] 2> 2488587 INFO (qtp1772586296-17600) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr
path=/update
params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:*
(-1558122511178137600)} 0 4
[junit4] 2> 2488587 INFO (qtp1652600308-17598) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica1] webapp=/solr
path=/update
params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:*
(-1558122511174991872)} 0 12
[junit4] 2> 2488588 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1]
o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr
path=/update params={wt=javabin&version=2}{deleteByQuery=*:*
(-1558122511174991872)} 0 18
[junit4] 2> 2488588 INFO (Thread-3392) [n:127.0.0.1:60291_solr c:dv_coll
s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.s.SolrIndexSearcher
Opening [Searcher@d900322[dv_coll_shard3_replica1] main]
[junit4] 2> 2488591 INFO (Thread-3392) [n:127.0.0.1:60291_solr c:dv_coll
s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.r.ManagedResourceStorage
Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2488592 INFO (Thread-3392) [n:127.0.0.1:60291_solr c:dv_coll
s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.r.ManagedResourceStorage
Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2488592 INFO (Thread-3392) [n:127.0.0.1:60291_solr c:dv_coll
s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.s.ZkIndexSchemaReader
Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2488597 INFO (qtp1772586296-17606) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2488597 INFO (qtp1772586296-17606) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2488597 INFO (qtp1772586296-17606) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2488597 INFO (qtp1772586296-17606) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
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=http://127.0.0.1:60290/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 1
[junit4] 2> 2488598 INFO (Thread-3392) [n:127.0.0.1:60291_solr c:dv_coll
s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.s.ZkIndexSchemaReader
Current schema version 1 is already the latest
[junit4] 2> 2488598 INFO (Thread-3392) [n:127.0.0.1:60291_solr c:dv_coll
s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.h.ReplicationHandler
Commits will be reserved for 10000
[junit4] 2> 2488598 INFO
(searcherExecutor-8066-thread-1-processing-n:127.0.0.1:60291_solr
x:dv_coll_shard3_replica1 s:shard3 c:dv_coll r:core_node1)
[n:127.0.0.1:60291_solr c:dv_coll s:shard3 r:core_node1
x:dv_coll_shard3_replica1] o.a.s.c.SolrCore [dv_coll_shard3_replica1]
Registered new searcher Searcher@d900322[dv_coll_shard3_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2488602 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2488602 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2488602 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2488602 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2488602 INFO (qtp1652600308-17596) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2488602 INFO (qtp1652600308-17596) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2488604 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@55430018[dv_coll_shard2_replica1]
main]
[junit4] 2> 2488604 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2488604 INFO
(searcherExecutor-8037-thread-1-processing-n:127.0.0.1:60290_solr
x:dv_coll_shard2_replica1 s:shard2 c:dv_coll r:core_node4)
[n:127.0.0.1:60290_solr c:dv_coll s:shard2 r:core_node4
x:dv_coll_shard2_replica1] o.a.s.c.SolrCore [dv_coll_shard2_replica1]
Registered new searcher Searcher@55430018[dv_coll_shard2_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2488604 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@295d8a45[dv_coll_shard1_replica1]
main]
[junit4] 2> 2488604 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
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=http://127.0.0.1:60290/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 2
[junit4] 2> 2488605 INFO (qtp1652600308-17596) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2488605 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2488605 INFO (qtp1652600308-17596) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1]
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=http://127.0.0.1:60290/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 3
[junit4] 2> 2488605 INFO
(searcherExecutor-8038-thread-1-processing-n:127.0.0.1:60291_solr
x:dv_coll_shard1_replica1 s:shard1 c:dv_coll r:core_node2)
[n:127.0.0.1:60291_solr c:dv_coll s:shard1 r:core_node2
x:dv_coll_shard1_replica1] o.a.s.c.SolrCore [dv_coll_shard1_replica1]
Registered new searcher Searcher@295d8a45[dv_coll_shard1_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2488605 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1]
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=http://127.0.0.1:60290/solr/dv_coll_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 3
[junit4] 2> 2488606 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
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 15
[junit4] 2> 2488611 INFO (Thread-3392) [n:127.0.0.1:60291_solr c:dv_coll
s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.u.DefaultSolrCoreState
New IndexWriter is ready to be used.
[junit4] 2> 2488619 INFO (qtp1652600308-17597) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1]
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
(1558122511212740608), 5 (1558122511215886336), 17 (1558122511215886337), 19
(1558122511215886338), 21 (1558122511215886339), 23 (1558122511215886340), 25
(1558122511215886341), 29 (1558122511216934912), 10030 (1558122511216934913),
33 (1558122511216934914), ... (13 adds)]} 0 4
[junit4] 2> 2488623 INFO (qtp1772586296-17605) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1]
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
(1558122511210643456), 8 (1558122511220080640), 10 (1558122511220080641), 11
(1558122511220080642), 13 (1558122511220080643), 14 (1558122511220080644),
10015 (1558122511220080645), 10020 (1558122511220080646), 24
(1558122511220080647), 27 (1558122511220080648), ... (16 adds)]} 0 10
[junit4] 2> 2488627 INFO (qtp1652600308-17598) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
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
(1558122511210643456), 4 (1558122511223226368), 10005 (1558122511223226369), 12
(1558122511224274944), 15 (1558122511224274945), 16 (1558122511224274946), 20
(1558122511224274947), 22 (1558122511224274948), 34 (1558122511224274949), 35
(1558122511224274950), ... (16 adds)]} 0 14
[junit4] 2> 2488632 INFO (qtp1772586296-17600) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
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
(1558122511211692032), 3 (1558122511223226368), 6 (1558122511228469248), 7
(1558122511229517824), 9 (1558122511229517825), 10010 (1558122511229517826), 18
(1558122511229517827), 10025 (1558122511229517828), 26 (1558122511229517829),
30 (1558122511229517830), ... (14 adds)]} 0 17
[junit4] 2> 2488636 INFO (qtp1772586296-17606) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2488636 INFO (qtp1772586296-17606) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@4adb056a
[junit4] 2> 2488637 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2488637 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@2b2a3fe7
[junit4] 2> 2488637 INFO (qtp1652600308-17595) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2488637 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2488638 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@56babb7b
[junit4] 2> 2488637 INFO (qtp1652600308-17595) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@1b64a7d6
[junit4] 2> 2488655 INFO (Thread-3392) [n:127.0.0.1:60291_solr c:dv_coll
s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.s.SolrIndexSearcher
Opening [Searcher@1cd02410[dv_coll_shard3_replica1] main]
[junit4] 2> 2488656 INFO (Thread-3392) [n:127.0.0.1:60291_solr c:dv_coll
s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.c.SolrCore config update
listener called for core dv_coll_shard1_replica1
[junit4] 2> 2488656 INFO
(searcherExecutor-8066-thread-1-processing-n:127.0.0.1:60291_solr
x:dv_coll_shard3_replica1 s:shard3 c:dv_coll r:core_node1)
[n:127.0.0.1:60291_solr c:dv_coll s:shard3 r:core_node1
x:dv_coll_shard3_replica1] o.a.s.c.SolrCore [dv_coll_shard3_replica1]
Registered new searcher Searcher@1cd02410[dv_coll_shard3_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C1)))}
[junit4] 2> 2488660 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@38f96d3c[dv_coll_shard4_replica1]
main]
[junit4] 2> 2488661 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2488661 INFO
(searcherExecutor-8057-thread-1-processing-n:127.0.0.1:60290_solr
x:dv_coll_shard4_replica1 s:shard4 c:dv_coll r:core_node3)
[n:127.0.0.1:60290_solr c:dv_coll s:shard4 r:core_node3
x:dv_coll_shard4_replica1] o.a.s.c.SolrCore [dv_coll_shard4_replica1]
Registered new searcher Searcher@38f96d3c[dv_coll_shard4_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C13)))}
[junit4] 2> 2488661 INFO (qtp1652600308-17593) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1]
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=http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 23
[junit4] 2> 2488664 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@7c6b5bf6[dv_coll_shard1_replica1]
main]
[junit4] 2> 2488664 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2488664 INFO
(searcherExecutor-8038-thread-1-processing-n:127.0.0.1:60291_solr
x:dv_coll_shard1_replica1 s:shard1 c:dv_coll r:core_node2)
[n:127.0.0.1:60291_solr c:dv_coll s:shard1 r:core_node2
x:dv_coll_shard1_replica1] o.a.s.c.SolrCore [dv_coll_shard1_replica1]
Registered new searcher Searcher@7c6b5bf6[dv_coll_shard1_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C16)))}
[junit4] 2> 2488665 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1]
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=http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 27
[junit4] 2> 2488665 INFO (qtp1652600308-17595) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@455cc208[dv_coll_shard2_replica1]
main]
[junit4] 2> 2488665 INFO (qtp1652600308-17595) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2488665 INFO
(searcherExecutor-8037-thread-1-processing-n:127.0.0.1:60290_solr
x:dv_coll_shard2_replica1 s:shard2 c:dv_coll r:core_node4)
[n:127.0.0.1:60290_solr c:dv_coll s:shard2 r:core_node4
x:dv_coll_shard2_replica1] o.a.s.c.SolrCore [dv_coll_shard2_replica1]
Registered new searcher Searcher@455cc208[dv_coll_shard2_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C16)))}
[junit4] 2> 2488666 INFO (qtp1652600308-17595) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
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=http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 28
[junit4] 2> 2488674 INFO (qtp1772586296-17606) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@7dfc1553[dv_coll_shard3_replica1]
main]
[junit4] 2> 2488675 INFO (qtp1772586296-17606) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2488675 INFO
(searcherExecutor-8061-thread-1-processing-n:127.0.0.1:60291_solr
x:dv_coll_shard3_replica1 s:shard3 c:dv_coll r:core_node1)
[n:127.0.0.1:60291_solr c:dv_coll s:shard3 r:core_node1
x:dv_coll_shard3_replica1] o.a.s.c.SolrCore [dv_coll_shard3_replica1]
Registered new searcher Searcher@7dfc1553[dv_coll_shard3_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C1)
Uninverting(_1(6.5.0):C13)))}
[junit4] 2> 2488675 INFO (qtp1772586296-17606) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
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=http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 38
[junit4] 2> 2488675 INFO (qtp1772586296-17606) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1] o.a.s.c.SolrCore
[dv_coll_shard3_replica1] CLOSING SolrCore
org.apache.solr.core.SolrCore@31b24449
[junit4] 2> 2488676 INFO (qtp1772586296-17606) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.dv_coll.shard3.replica1
[junit4] 2> 2488676 INFO (qtp1772586296-17603) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1]
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 41
[junit4] 2> 2488698 INFO (qtp1772586296-17604) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1] 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=http://127.0.0.1:60291/solr/dv_coll_shard3_replica1/&rows=100&version=2&q=*:*&NOW=1485941420825&isShard=true&wt=javabin&group.field=intGSF&group=true}
status=0 QTime=10
[junit4] 2> 2488699 INFO (qtp1772586296-17605) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1] 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=http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/&rows=100&version=2&q=*:*&NOW=1485941420825&isShard=true&wt=javabin&group.field=intGSF&group=true}
status=0 QTime=11
[junit4] 2> 2488698 INFO (qtp1652600308-17590) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1] 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=http://127.0.0.1:60290/solr/dv_coll_shard2_replica1/&rows=100&version=2&q=*:*&NOW=1485941420825&isShard=true&wt=javabin&group.field=intGSF&group=true}
status=0 QTime=11
[junit4] 2> 2488698 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1] 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=http://127.0.0.1:60290/solr/dv_coll_shard4_replica1/&rows=100&version=2&q=*:*&NOW=1485941420825&isShard=true&wt=javabin&group.field=intGSF&group=true}
status=0 QTime=1
[junit4] 2> 2488705 INFO (qtp1772586296-17600) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1] 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=http://127.0.0.1:60291/solr/dv_coll_shard3_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1485941420825&group.topgroups.intGSF=579562973&group.topgroups.intGSF=%01&group.topgroups.intGSF=579572980&group.topgroups.intGSF=579582981&group.topgroups.intGSF=579592988&group.topgroups.intGSF=579602993&group.topgroups.intGSF=579613002&group.topgroups.intGSF=579623006&isShard=true&wt=javabin&group.field=intGSF&group=true}
status=0 QTime=1
[junit4] 2> 2488705 INFO (qtp1652600308-17597) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1] 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=http://127.0.0.1:60290/solr/dv_coll_shard2_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1485941420825&group.topgroups.intGSF=579562973&group.topgroups.intGSF=%01&group.topgroups.intGSF=579572980&group.topgroups.intGSF=579582981&group.topgroups.intGSF=579592988&group.topgroups.intGSF=579602993&group.topgroups.intGSF=579613002&group.topgroups.intGSF=579623006&isShard=true&wt=javabin&group.field=intGSF&group=true}
status=0 QTime=1
[junit4] 2> 2488706 INFO (qtp1652600308-17598) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1] 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=http://127.0.0.1:60290/solr/dv_coll_shard4_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1485941420825&group.topgroups.intGSF=579562973&group.topgroups.intGSF=%01&group.topgroups.intGSF=579572980&group.topgroups.intGSF=579582981&group.topgroups.intGSF=579592988&group.topgroups.intGSF=579602993&group.topgroups.intGSF=579613002&group.topgroups.intGSF=579623006&isShard=true&wt=javabin&group.field=intGSF&group=true}
status=0 QTime=0
[junit4] 2> 2488706 INFO (qtp1772586296-17589) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1] 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=http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/&rows=100&version=2&group.distributed.second=true&q=*:*&NOW=1485941420825&group.topgroups.intGSF=579562973&group.topgroups.intGSF=%01&group.topgroups.intGSF=579572980&group.topgroups.intGSF=579582981&group.topgroups.intGSF=579592988&group.topgroups.intGSF=579602993&group.topgroups.intGSF=579613002&group.topgroups.intGSF=579623006&isShard=true&wt=javabin&group.field=intGSF&group=true}
status=0 QTime=0
[junit4] 2> 2488710 INFO (qtp1652600308-17597) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1] 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=http://127.0.0.1:60290/solr/dv_coll_shard2_replica1/&rows=100&version=2&q=*:*&NOW=1485941420825&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> 2488710 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1] 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=http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/&rows=100&version=2&q=*:*&NOW=1485941420825&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> 2488712 INFO (qtp1772586296-17606) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1] 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=http://127.0.0.1:60291/solr/dv_coll_shard3_replica1/&rows=100&version=2&q=*:*&NOW=1485941420825&ids=2&isShard=true&wt=javabin&group.field=intGSF}
status=0 QTime=0
[junit4] 2> 2488712 INFO (qtp1652600308-17595) [n:127.0.0.1:60290_solr
c:dv_coll s:shard4 r:core_node3 x:dv_coll_shard4_replica1] 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=http://127.0.0.1:60290/solr/dv_coll_shard4_replica1/&rows=100&version=2&q=*:*&NOW=1485941420825&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> 2488714 INFO (qtp1652600308-17596) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1] o.a.s.c.S.Request
[dv_coll_shard2_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=32
[junit4] 2> 2488715 INFO
(TEST-DocValuesNotIndexedTest.testGroupingDVOnly-seed#[FF059E9D84C926FE]) [
] o.a.s.SolrTestCaseJ4 ###Ending testGroupingDVOnly
[junit4] 2> NOTE: reproduce with: ant test
-Dtestcase=DocValuesNotIndexedTest -Dtests.method=testGroupingDVOnly
-Dtests.seed=FF059E9D84C926FE -Dtests.slow=true -Dtests.locale=tr
-Dtests.timezone=Pacific/Funafuti -Dtests.asserts=true
-Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 0.32s J0 | DocValuesNotIndexedTest.testGroupingDVOnly <<<
[junit4] > Throwable #1: java.lang.AssertionError: Unexpected number of
elements in the group for intGSF: 5
[junit4] > at
__randomizedtesting.SeedInfo.seed([FF059E9D84C926FE:64BEF0C5C99114A0]:0)
[junit4] > at
org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingDVOnly(DocValuesNotIndexedTest.java:376)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2488802 INFO
(TEST-DocValuesNotIndexedTest.testGroupingSorting-seed#[FF059E9D84C926FE]) [
] o.a.s.SolrTestCaseJ4 ###Starting testGroupingSorting
[junit4] 2> 2488809 INFO (qtp1772586296-17601) [n:127.0.0.1:60291_solr
c:dv_coll s:shard1 r:core_node2 x:dv_coll_shard1_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@5543f3f9[dv_coll_shard1_replica1]
realtime]
[junit4] 2> 2488816 INFO (qtp1772586296-17605) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@1c27fb50[dv_coll_shard3_replica1]
realtime]
[junit4] 2> 2488817 INFO (qtp1772586296-17605) [n:127.0.0.1:60291_solr
c:dv_coll s:shard3 r:core_node1 x:dv_coll_shard3_replica1]
o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr
path=/update
params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:*
(-1558122511416164352)} 0 7
[junit4] 2> 2488819 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@6637873e[dv_coll_shard2_replica1]
realtime]
[junit4] 2> 2488819 INFO (qtp1652600308-17594) [n:127.0.0.1:60290_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica1] webapp=/solr
path=/update
params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:60291/solr/dv_coll_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:*
(-155812251141
[...truncated too long message...]
] 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> 2489621 INFO (coreCloseExecutor-8071-thread-2)
[n:127.0.0.1:60291_solr c:dv_coll s:shard3 r:core_node1
x:dv_coll_shard3_replica1] o.a.s.m.SolrMetricManager Closing metric reporters
for: solr.core.dv_coll.shard3.replica1
[junit4] 2> 2489622 INFO (coreCloseExecutor-8071-thread-1)
[n:127.0.0.1:60291_solr c:dv_coll s:shard1 r:core_node2
x:dv_coll_shard1_replica1] o.a.s.m.SolrMetricManager Closing metric reporters
for: solr.core.dv_coll.shard1.replica1
[junit4] 2> 2489626 INFO (coreCloseExecutor-8070-thread-2)
[n:127.0.0.1:60290_solr c:dv_coll s:shard2 r:core_node4
x:dv_coll_shard2_replica1] o.a.s.m.SolrMetricManager Closing metric reporters
for: solr.core.dv_coll.shard2.replica1
[junit4] 2> 2489639 INFO (jetty-launcher-3461-thread-1) [ ]
o.a.s.c.Overseer Overseer
(id=97382656622002181-127.0.0.1:60290_solr-n_0000000000) closing
[junit4] 2> 2489639 INFO
(OverseerStateUpdate-97382656622002181-127.0.0.1:60290_solr-n_0000000000)
[n:127.0.0.1:60290_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:60290_solr
[junit4] 2> 2489649 WARN
(zkCallback-3471-thread-1-processing-n:127.0.0.1:60290_solr)
[n:127.0.0.1:60290_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 2489649 WARN
(zkCallback-3472-thread-2-processing-n:127.0.0.1:60291_solr)
[n:127.0.0.1:60291_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 2489650 INFO (jetty-launcher-3461-thread-1) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 2489654 INFO (jetty-launcher-3461-thread-2) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 2489654 INFO (jetty-launcher-3461-thread-1) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@41ed1014{/solr,null,UNAVAILABLE}
[junit4] 2> 2489654 INFO (jetty-launcher-3461-thread-2) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@405472a2{/solr,null,UNAVAILABLE}
[junit4] 2> 2489664 INFO
(SUITE-DocValuesNotIndexedTest-seed#[FF059E9D84C926FE]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:60288 60288
[junit4] 2> 2489682 INFO (Thread-3372) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:60288 60288
[junit4] 2> 2494306 WARN (Thread-3372) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/configs/conf1/managed-schema
[junit4] 2> 4 /solr/configs/conf1
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 3 /solr/clusterprops.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> 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> 13 /solr/overseer/queue
[junit4] 2> 5 /solr/overseer/collection-queue-work
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2> 3 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> 2494306 INFO
(SUITE-DocValuesNotIndexedTest-seed#[FF059E9D84C926FE]-worker) [ ]
o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at:
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_FF059E9D84C926FE-001
[junit4] 2> NOTE: test params are: codec=Lucene62,
sim=RandomSimilarity(queryNorm=false,coord=no): {}, locale=tr,
timezone=Pacific/Funafuti
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_121
(64-bit)/cpus=3,threads=1,free=179510592,total=500928512
[junit4] 2> NOTE: All tests run in this JVM: [ZkCLITest,
PingRequestHandlerTest, TestExtendedDismaxParser, SolrGangliaReporterTest,
MigrateRouteKeyTest, TestXmlQParserPlugin, ActionThrottleTest,
AnalyticsQueryTest, TestBinaryResponseWriter, TestFieldCacheWithThreads,
TestFieldCacheSortRandom, IndexBasedSpellCheckerTest, DisMaxRequestHandlerTest,
TestBM25SimilarityFactory, TestComponentsName,
DistributedFacetPivotSmallAdvancedTest, GraphQueryTest,
TestSerializedLuceneMatchVersion, TestSQLHandlerNonCloud, CustomCollectionTest,
TestRemoteStreaming, TestSurroundQueryParser, OutputWriterTest,
TestRawResponseWriter, TestPKIAuthenticationPlugin, TestCloudSchemaless,
TestRestoreCore, HardAutoCommitTest, TestSolrQueryResponse,
ClusterStateUpdateTest, TestGeoJSONResponseWriter, HttpSolrCallGetCoreTest,
ConnectionManagerTest, HLLUtilTest, TestBinaryField, AssignTest,
TestQueryWrapperFilter, CoreAdminRequestStatusTest,
PKIAuthenticationIntegrationTest, TestPseudoReturnFields, SolrCloudExampleTest,
SolrJmxReporterTest, TestLeaderElectionZkExpiry,
ConjunctionSolrSpellCheckerTest, CloudMLTQParserTest,
TestSweetSpotSimilarityFactory, AnalysisErrorHandlingTest, TestCharFilters,
TestMacros, DocumentBuilderTest, TestStressVersions, AlternateDirectoryTest,
TestNumericTerms32, HdfsChaosMonkeyNothingIsSafeTest, TestRandomDVFaceting,
DocValuesMissingTest, TestDynamicLoading, CursorPagingTest,
BaseCdcrDistributedZkTest, HdfsRestartWhileUpdatingTest, FacetPivotSmallTest,
DistributedQueryComponentOptimizationTest, AtomicUpdatesTest,
TestGroupingSearch, TestMiniSolrCloudCluster, TestCSVLoader,
CollectionsAPIAsyncDistributedZkTest, TestSchemaSimilarityResource,
ConcurrentDeleteAndCreateCollectionTest, BitVectorTest, TestHashPartitioner,
LeaderElectionTest, SolrCoreTest, SharedFSAutoReplicaFailoverTest,
TestPerFieldSimilarity, DirectSolrConnectionTest, TestCorePropertiesReload,
CloneFieldUpdateProcessorFactoryTest, SimpleCollectionCreateDeleteTest,
TestFastOutputStream, TestSolrCloudWithSecureImpersonation,
OverseerModifyCollectionTest, TestShardHandlerFactory, TestDefaultStatsCache,
SolrTestCaseJ4Test, TestScoreJoinQPScore, TestShortCircuitedRequests,
TestConfigSetsAPI, HdfsCollectionsAPIDistributedZkTest, ShardRoutingTest,
SuggesterFSTTest, MoreLikeThisHandlerTest, MergeStrategyTest,
TestTestInjection, MetricUtilsTest, TestWordDelimiterFilterFactory,
TestDynamicFieldCollectionResource, PreAnalyzedUpdateProcessorTest,
SynonymTokenizerTest, RequiredFieldsTest, TestStandardQParsers,
HdfsBasicDistributedZk2Test, TestConfigOverlay, RecoveryZkTest,
TolerantUpdateProcessorTest, TestManagedSchemaThreadSafety,
PathHierarchyTokenizerFactoryTest, TestDocumentBuilder, TestStressReorder,
XsltUpdateRequestHandlerTest, TestFaceting, DataDrivenBlockJoinTest,
TestTolerantSearch, TestIntervalFaceting, BadComponentTest,
SecurityConfHandlerTest, DeleteReplicaTest, SpatialRPTFieldTypeTest,
DirectSolrSpellCheckerTest, TestSolrDeletionPolicy1,
TestDistributedStatsComponentCardinality, ChaosMonkeyNothingIsSafeTest,
TestPartialUpdateDeduplication, TestMiniSolrCloudClusterSSL,
TestNonDefinedSimilarityFactory, RulesTest, QueryElevationComponentTest,
SchemaVersionSpecificBehaviorTest, TestJettySolrRunner, PeerSyncTest,
SimpleFacetsTest, TestSolrCoreParser, TestFilteredDocIdSet, TestXIncludeConfig,
SimplePostToolTest, JSONWriterTest, TestAuthenticationFramework, SampleTest,
ZkControllerTest, DistribDocExpirationUpdateProcessorTest, TestStressLiveNodes,
TestJsonFacets, FullHLLTest, TestSolrCloudWithDelegationTokens,
TestCopyFieldCollectionResource, DistributedQueueTest, SystemInfoHandlerTest,
TestComplexPhraseLeadingWildcard, MultiThreadedOCPTest,
TestDeleteCollectionOnDownNodes, TestCSVResponseWriter,
DistributedSpellCheckComponentTest, StatsReloadRaceTest, BufferStoreTest,
PeerSyncReplicationTest, BlockJoinFacetRandomTest, TestManagedResourceStorage,
PrimUtilsTest, TestReplicationHandler, OpenExchangeRatesOrgProviderTest,
TestFieldTypeCollectionResource, NumericFieldsTest, QueryEqualityTest,
BlockCacheTest, HighlighterTest, ChaosMonkeySafeLeaderTest,
UnloadDistributedZkTest, OverseerTest, TestRandomFaceting, TestZkChroot,
TestRecovery, TestRealTimeGet, DistributedTermsComponentTest, TestRangeQuery,
TestCoreContainer, ConvertedLegacyTest, TestSort, TestFiltering,
TestFunctionQuery, BasicFunctionalityTest, TestLazyCores,
DirectUpdateHandlerTest, TestBadConfig, TestIndexSearcher, SoftAutoCommitTest,
CurrencyFieldOpenExchangeTest, DistributedQueryElevationComponentTest,
CurrencyFieldXmlFileTest, AnalysisAfterCoreReloadTest,
SignatureUpdateProcessorFactoryTest, SolrRequestParserTest, DocValuesTest,
TestStressLucene, TestTrie, SpatialFilterTest, PolyFieldTest, TestUpdate,
DefaultValueUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest,
SortByFunctionTest, DocValuesMultiTest, CacheHeaderTest,
LukeRequestHandlerTest, StandardRequestHandlerTest,
DocumentAnalysisRequestHandlerTest, PrimitiveFieldTypeTest,
FileBasedSpellCheckerTest, TermsComponentTest, XmlUpdateRequestHandlerTest,
RequestHandlersTest, FieldAnalysisRequestHandlerTest, TestSolrQueryParser,
FastVectorHighlighterTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest,
TestJmxIntegration, TestCollationField, UpdateRequestProcessorFactoryTest,
MBeansHandlerTest, QueryParsingTest, TestAnalyzedSuggestions, JsonLoaderTest,
SearchHandlerTest, HighlighterConfigTest, SOLR749Test, TestSolrIndexConfig,
CopyFieldTest, TestStressRecovery, CloudExitableDirectoryReaderTest,
CollectionStateFormat2Test, DeleteLastCustomShardedReplicaTest,
DeleteShardTest, DistribJoinFromCollectionTest, DocValuesNotIndexedTest]
[junit4] Completed [475/681 (1!)] on J0 in 10.74s, 4 tests, 1 failure <<<
FAILURES!
[...truncated 63131 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
