Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/3798/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingSorting
Error Message:
Should have exactly 4 documents returned expected:<4> but was:<3>
Stack Trace:
java.lang.AssertionError: Should have exactly 4 documents returned expected:<4>
but was:<3>
at
__randomizedtesting.SeedInfo.seed([36B7C7B063946B0B:288FCFB81F3FD18B]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at
org.apache.solr.cloud.DocValuesNotIndexedTest.checkSortOrder(DocValuesNotIndexedTest.java:259)
at
org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingSorting(DocValuesNotIndexedTest.java:244)
at 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 12209 lines...]
[junit4] Suite: org.apache.solr.cloud.DocValuesNotIndexedTest
[junit4] 2> Creating dataDir:
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/init-core-data-001
[junit4] 2> 2402936 INFO
(SUITE-DocValuesNotIndexedTest-seed#[36B7C7B063946B0B]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields
[junit4] 2> 2402943 INFO
(SUITE-DocValuesNotIndexedTest-seed#[36B7C7B063946B0B]-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> 2402945 INFO
(SUITE-DocValuesNotIndexedTest-seed#[36B7C7B063946B0B]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001
[junit4] 2> 2402945 INFO
(SUITE-DocValuesNotIndexedTest-seed#[36B7C7B063946B0B]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2402946 INFO (Thread-3490) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2402946 INFO (Thread-3490) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 2403051 INFO
(SUITE-DocValuesNotIndexedTest-seed#[36B7C7B063946B0B]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:53916
[junit4] 2> 2403260 INFO (jetty-launcher-2861-thread-1) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2403262 INFO (jetty-launcher-2861-thread-2) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2403264 INFO (jetty-launcher-2861-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@6417bf1d{/solr,null,AVAILABLE}
[junit4] 2> 2403264 INFO (jetty-launcher-2861-thread-1) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@5962d615{HTTP/1.1,[http/1.1]}{127.0.0.1:53918}
[junit4] 2> 2403264 INFO (jetty-launcher-2861-thread-1) [ ]
o.e.j.s.Server Started @2433856ms
[junit4] 2> 2403264 INFO (jetty-launcher-2861-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=53918}
[junit4] 2> 2403264 ERROR (jetty-launcher-2861-thread-1) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 2403265 INFO (jetty-launcher-2861-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.0.0
[junit4] 2> 2403265 INFO (jetty-launcher-2861-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2403265 INFO (jetty-launcher-2861-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2403265 INFO (jetty-launcher-2861-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-01-25T23:45:08.636Z
[junit4] 2> 2403269 INFO (jetty-launcher-2861-thread-2) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@574b78af{/solr,null,AVAILABLE}
[junit4] 2> 2403269 INFO (jetty-launcher-2861-thread-2) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@7ab1375e{HTTP/1.1,[http/1.1]}{127.0.0.1:53919}
[junit4] 2> 2403270 INFO (jetty-launcher-2861-thread-2) [ ]
o.e.j.s.Server Started @2433862ms
[junit4] 2> 2403270 INFO (jetty-launcher-2861-thread-2) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=53919}
[junit4] 2> 2403270 ERROR (jetty-launcher-2861-thread-2) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 2403271 INFO (jetty-launcher-2861-thread-2) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.0.0
[junit4] 2> 2403271 INFO (jetty-launcher-2861-thread-2) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2403271 INFO (jetty-launcher-2861-thread-2) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2403271 INFO (jetty-launcher-2861-thread-2) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-01-25T23:45:08.642Z
[junit4] 2> 2403280 INFO (jetty-launcher-2861-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2403281 INFO (jetty-launcher-2861-thread-2) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2403293 INFO (jetty-launcher-2861-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53916/solr
[junit4] 2> 2403297 INFO (jetty-launcher-2861-thread-2) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53916/solr
[junit4] 2> 2403367 INFO (jetty-launcher-2861-thread-2)
[n:127.0.0.1:53919_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:53919_solr
[junit4] 2> 2403369 INFO (jetty-launcher-2861-thread-1)
[n:127.0.0.1:53918_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:53918_solr
[junit4] 2> 2403370 INFO (jetty-launcher-2861-thread-2)
[n:127.0.0.1:53919_solr ] o.a.s.c.Overseer Overseer
(id=97346381959790598-127.0.0.1:53919_solr-n_0000000000) starting
[junit4] 2> 2403373 INFO
(zkCallback-2871-thread-1-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 2403374 INFO
(zkCallback-2872-thread-1-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 2403393 INFO (jetty-launcher-2861-thread-2)
[n:127.0.0.1:53919_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:53919_solr
[junit4] 2> 2403396 INFO
(zkCallback-2872-thread-1-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 2403397 INFO
(zkCallback-2871-thread-1-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 2404081 INFO (jetty-launcher-2861-thread-1)
[n:127.0.0.1:53918_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001/node1/.
[junit4] 2> 2404086 INFO (jetty-launcher-2861-thread-2)
[n:127.0.0.1:53919_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001/node2/.
[junit4] 2> 2405587 INFO
(SUITE-DocValuesNotIndexedTest-seed#[36B7C7B063946B0B]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2405591 INFO
(SUITE-DocValuesNotIndexedTest-seed#[36B7C7B063946B0B]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:53916/solr ready
[junit4] 2> 2405619 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_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> 2405623 INFO
(OverseerThreadFactory-8238-thread-1-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_solr ] o.a.s.c.CreateCollectionCmd Create collection
dv_coll
[junit4] 2> 2405745 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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> 2405745 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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> 2405745 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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> 2405749 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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> 2405868 INFO
(zkCallback-2871-thread-1-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_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> 2405868 INFO
(zkCallback-2872-thread-3-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_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> 2406789 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.c.SolrConfig Using Lucene
MatchVersion: 7.0.0
[junit4] 2> 2406790 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.c.SolrConfig Using Lucene
MatchVersion: 7.0.0
[junit4] 2> 2406791 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.c.SolrConfig Using Lucene
MatchVersion: 7.0.0
[junit4] 2> 2406796 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.c.SolrConfig Using Lucene
MatchVersion: 7.0.0
[junit4] 2> 2406801 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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> 2406806 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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> 2406808 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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> 2406811 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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> 2406813 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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> 2406813 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001/node1/dv_coll_shard2_replica1],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001/node1/./dv_coll_shard2_replica1/data/]
[junit4] 2> 2406815 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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> 2406816 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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> 2406817 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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> 2406818 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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> 2406819 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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> 2406819 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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> 2406819 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001/node2/dv_coll_shard3_replica1],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001/node2/./dv_coll_shard3_replica1/data/]
[junit4] 2> 2406819 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001/node2/dv_coll_shard1_replica1],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001/node2/./dv_coll_shard1_replica1/data/]
[junit4] 2> 2406821 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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> 2406821 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001/node1/dv_coll_shard4_replica1],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001/node1/./dv_coll_shard4_replica1/data/]
[junit4] 2> 2406862 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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> 2406862 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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> 2406865 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.u.CommitTracker Hard
AutoCommit: disabled
[junit4] 2> 2406865 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.u.CommitTracker Soft
AutoCommit: disabled
[junit4] 2> 2406875 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.s.SolrIndexSearcher
Opening [Searcher@6e42e2bb[dv_coll_shard2_replica1] main]
[junit4] 2> 2406876 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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> 2406876 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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> 2406879 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.u.CommitTracker Hard
AutoCommit: disabled
[junit4] 2> 2406879 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.u.CommitTracker Soft
AutoCommit: disabled
[junit4] 2> 2406880 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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> 2406880 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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> 2406881 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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> 2406881 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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> 2406883 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.u.CommitTracker Hard
AutoCommit: disabled
[junit4] 2> 2406883 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.r.ManagedResourceStorage
Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2406883 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.u.CommitTracker Soft
AutoCommit: disabled
[junit4] 2> 2406884 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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> 2406884 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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> 2406885 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.u.CommitTracker Hard
AutoCommit: disabled
[junit4] 2> 2406885 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.u.CommitTracker Soft
AutoCommit: disabled
[junit4] 2> 2406885 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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> 2406886 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.h.ReplicationHandler
Commits will be reserved for 10000
[junit4] 2> 2406886 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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 1557542115482796032
[junit4] 2> 2406886 INFO
(searcherExecutor-8243-thread-1-processing-n:127.0.0.1:53918_solr
x:dv_coll_shard2_replica1 s:shard2 c:dv_coll) [n:127.0.0.1:53918_solr c:dv_coll
s:shard2 x:dv_coll_shard2_replica1] o.a.s.c.SolrCore [dv_coll_shard2_replica1]
Registered new searcher Searcher@6e42e2bb[dv_coll_shard2_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2406887 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.s.SolrIndexSearcher
Opening [Searcher@6517068e[dv_coll_shard3_replica1] main]
[junit4] 2> 2406890 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.r.ManagedResourceStorage
Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2406890 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.s.SolrIndexSearcher
Opening [Searcher@67d8b358[dv_coll_shard4_replica1] main]
[junit4] 2> 2406893 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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> 2406894 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.r.ManagedResourceStorage
Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2406895 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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> 2406895 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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> 2406898 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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> 2406898 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.h.ReplicationHandler
Commits will be reserved for 10000
[junit4] 2> 2406898 INFO
(searcherExecutor-8246-thread-1-processing-n:127.0.0.1:53918_solr
x:dv_coll_shard4_replica1 s:shard4 c:dv_coll) [n:127.0.0.1:53918_solr c:dv_coll
s:shard4 x:dv_coll_shard4_replica1] o.a.s.c.SolrCore [dv_coll_shard4_replica1]
Registered new searcher Searcher@67d8b358[dv_coll_shard4_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2406899 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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 1557542115496427520
[junit4] 2> 2406903 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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> 2406905 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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> 2406906 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.h.ReplicationHandler
Commits will be reserved for 10000
[junit4] 2> 2406906 INFO
(searcherExecutor-8245-thread-1-processing-n:127.0.0.1:53919_solr
x:dv_coll_shard3_replica1 s:shard3 c:dv_coll) [n:127.0.0.1:53919_solr c:dv_coll
s:shard3 x:dv_coll_shard3_replica1] o.a.s.c.SolrCore [dv_coll_shard3_replica1]
Registered new searcher Searcher@6517068e[dv_coll_shard3_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2406906 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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 1557542115503767552
[junit4] 2> 2406913 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2406913 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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> 2406913 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.c.SyncStrategy Sync
replicas to http://127.0.0.1:53918/solr/dv_coll_shard4_replica1/
[junit4] 2> 2406913 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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> 2406913 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 x:dv_coll_shard4_replica1] o.a.s.c.SyncStrategy
http://127.0.0.1:53918/solr/dv_coll_shard4_replica1/ has no replicas
[junit4] 2> 2406917 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2406918 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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> 2406918 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.c.SyncStrategy Sync
replicas to http://127.0.0.1:53918/solr/dv_coll_shard2_replica1/
[junit4] 2> 2406918 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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> 2406919 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 x:dv_coll_shard2_replica1] o.a.s.c.SyncStrategy
http://127.0.0.1:53918/solr/dv_coll_shard2_replica1/ has no replicas
[junit4] 2> 2406923 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2406923 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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> 2406923 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.c.SyncStrategy Sync
replicas to http://127.0.0.1:53919/solr/dv_coll_shard3_replica1/
[junit4] 2> 2406923 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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> 2406923 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 x:dv_coll_shard3_replica1] o.a.s.c.SyncStrategy
http://127.0.0.1:53919/solr/dv_coll_shard3_replica1/ has no replicas
[junit4] 2> 2406924 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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:53918/solr/dv_coll_shard4_replica1/ shard4
[junit4] 2> 2406930 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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:53918/solr/dv_coll_shard2_replica1/ shard2
[junit4] 2> 2406930 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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:53919/solr/dv_coll_shard3_replica1/ shard3
[junit4] 2> 2406936 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.s.SolrIndexSearcher
Opening [Searcher@5c9c30de[dv_coll_shard1_replica1] main]
[junit4] 2> 2406939 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.r.ManagedResourceStorage
Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2406940 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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> 2406940 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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> 2406942 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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> 2406942 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.h.ReplicationHandler
Commits will be reserved for 10000
[junit4] 2> 2406942 INFO
(searcherExecutor-8244-thread-1-processing-n:127.0.0.1:53919_solr
x:dv_coll_shard1_replica1 s:shard1 c:dv_coll) [n:127.0.0.1:53919_solr c:dv_coll
s:shard1 x:dv_coll_shard1_replica1] o.a.s.c.SolrCore [dv_coll_shard1_replica1]
Registered new searcher Searcher@5c9c30de[dv_coll_shard1_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2406942 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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 1557542115541516288
[junit4] 2> 2406955 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2406955 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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> 2406955 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.c.SyncStrategy Sync
replicas to http://127.0.0.1:53919/solr/dv_coll_shard1_replica1/
[junit4] 2> 2406955 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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> 2406955 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 x:dv_coll_shard1_replica1] o.a.s.c.SyncStrategy
http://127.0.0.1:53919/solr/dv_coll_shard1_replica1/ has no replicas
[junit4] 2> 2406963 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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:53919/solr/dv_coll_shard1_replica1/ shard1
[junit4] 2> 2407075 INFO
(zkCallback-2872-thread-1-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_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> 2407076 INFO
(zkCallback-2871-thread-1-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_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> 2407081 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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> 2407087 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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=1342
[junit4] 2> 2407097 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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> 2407098 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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> 2407108 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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> 2407103 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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=1355
[junit4] 2> 2407115 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_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=1370
[junit4] 2> 2407129 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_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=1383
[junit4] 2> 2407138 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_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> 2407229 INFO
(zkCallback-2871-thread-1-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_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> 2407229 INFO
(zkCallback-2872-thread-3-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_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> 2407638 INFO
(OverseerCollectionConfigSetProcessor-97346381959790598-127.0.0.1:53919_solr-n_0000000000)
[n:127.0.0.1:53919_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> 2408140 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_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=2521
[junit4] 2> 2408189 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.s.SchemaManager managed schema loaded . version : 0
[junit4] 2> 2408199 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.s.IndexSchema
[dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 2408201 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.s.IndexSchema
Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2408214 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.c.ZkController
Persisted config data to node /configs/conf1/managed-schema
[junit4] 2> 2408215 INFO
(zkCallback-2872-thread-1-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_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> 2408215 INFO
(zkCallback-2871-thread-2-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_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> 2408215 INFO
(zkCallback-2872-thread-3-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_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> 2408218 INFO
(zkCallback-2871-thread-1-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_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> 2408218 INFO
(zkCallback-2871-thread-2-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_solr ] o.a.s.s.ZkIndexSchemaReader Retrieved schema
version 1 from ZooKeeper
[junit4] 2> 2408220 INFO
(zkCallback-2871-thread-2-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_solr ] o.a.s.s.IndexSchema [dv_coll_shard2_replica1]
Schema name=minimal
[junit4] 2> 2408223 INFO
(zkCallback-2871-thread-2-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with
uniqueid field id
[junit4] 2> 2408224 INFO
(zkCallback-2871-thread-2-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_solr ] o.a.s.s.ZkIndexSchemaReader Finished refreshing
schema in 5 ms
[junit4] 2> 2408224 INFO
(zkCallback-2872-thread-1-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_solr ] o.a.s.s.ZkIndexSchemaReader Retrieved schema
version 1 from ZooKeeper
[junit4] 2> 2408226 INFO
(zkCallback-2872-thread-1-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_solr ] o.a.s.s.IndexSchema [dv_coll_shard1_replica1]
Schema name=minimal
[junit4] 2> 2408229 INFO
(zkCallback-2871-thread-1-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_solr ] o.a.s.s.ZkIndexSchemaReader Retrieved schema
version 1 from ZooKeeper
[junit4] 2> 2408229 INFO (Thread-3509) [n:127.0.0.1:53919_solr ]
o.a.s.c.SolrCore config update listener called for core dv_coll_shard3_replica1
[junit4] 2> 2408230 INFO
(zkCallback-2872-thread-1-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with
uniqueid field id
[junit4] 2> 2408231 INFO
(zkCallback-2872-thread-1-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_solr ] o.a.s.s.ZkIndexSchemaReader Finished refreshing
schema in 6 ms
[junit4] 2> 2408231 INFO (Thread-3510) [n:127.0.0.1:53918_solr ]
o.a.s.c.SolrCore config update listener called for core dv_coll_shard2_replica1
[junit4] 2> 2408232 INFO
(zkCallback-2871-thread-1-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_solr ] o.a.s.s.IndexSchema [dv_coll_shard4_replica1]
Schema name=minimal
[junit4] 2> 2408236 INFO
(zkCallback-2871-thread-1-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with
uniqueid field id
[junit4] 2> 2408236 INFO
(zkCallback-2871-thread-1-processing-n:127.0.0.1:53918_solr)
[n:127.0.0.1:53918_solr ] o.a.s.s.ZkIndexSchemaReader Finished refreshing
schema in 6 ms
[junit4] 2> 2408237 INFO (Thread-3509) [n:127.0.0.1:53919_solr ]
o.a.s.c.SolrCore core reload dv_coll_shard3_replica1
[junit4] 2> 2408238 INFO (Thread-3510) [n:127.0.0.1:53918_solr ]
o.a.s.c.SolrCore config update listener called for core dv_coll_shard4_replica1
[junit4] 2> 2408243 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.c.SolrConfig
Using Lucene MatchVersion: 7.0.0
[junit4] 2> 2408250 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.s.IndexSchema
[dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 2408254 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.s.IndexSchema
Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2408255 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.c.CoreContainer Reloading SolrCore 'dv_coll_shard3_replica1' using
configuration from collection dv_coll
[junit4] 2> 2408256 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.c.SolrCore
[[dv_coll_shard3_replica1] ] Opening new SolrCore at
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001/node2/dv_coll_shard3_replica1],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001/node2/./dv_coll_shard3_replica1/data/]
[junit4] 2> 2408278 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2408278 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2408278 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@1f08b308[dv_coll_shard3_replica1]
main]
[junit4] 2> 2408280 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 2408281 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2408281 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at
/configs/conf1/managed-schema
[junit4] 2> 2408282 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.s.ZkIndexSchemaReader Current schema version 1 is already the latest
[junit4] 2> 2408282 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2408282 INFO
(searcherExecutor-8263-thread-1-processing-n:127.0.0.1:53919_solr
x:dv_coll_shard3_replica1 s:shard3 c:dv_coll r:core_node2)
[n:127.0.0.1:53919_solr c:dv_coll s:shard3 r:core_node2
x:dv_coll_shard3_replica1] o.a.s.c.SolrCore [dv_coll_shard3_replica1]
Registered new searcher Searcher@1f08b308[dv_coll_shard3_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2408283 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.u.UpdateLog
Could not find max version in index or recent updates, using new clock
1557542116947656704
[junit4] 2> 2408291 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 2408291 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@7765a366[dv_coll_shard3_replica1]
main]
[junit4] 2> 2408292 INFO
(searcherExecutor-8263-thread-1-processing-n:127.0.0.1:53919_solr
x:dv_coll_shard3_replica1 s:shard3 c:dv_coll r:core_node2)
[n:127.0.0.1:53919_solr c:dv_coll s:shard3 r:core_node2
x:dv_coll_shard3_replica1] o.a.s.c.SolrCore [dv_coll_shard3_replica1]
Registered new searcher Searcher@7765a366[dv_coll_shard3_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2408292 INFO
(zkCallback-2872-thread-3-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_solr ] o.a.s.s.ZkIndexSchemaReader Retrieved schema
version 1 from ZooKeeper
[junit4] 2> 2408296 INFO
(zkCallback-2872-thread-3-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_solr ] o.a.s.s.IndexSchema [dv_coll_shard3_replica1]
Schema name=minimal
[junit4] 2> 2408323 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 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> 2408323 INFO (Thread-3509) [n:127.0.0.1:53919_solr ]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 2408323 INFO
(zkCallback-2872-thread-3-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with
uniqueid field id
[junit4] 2> 2408323 INFO
(zkCallback-2872-thread-3-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_solr ] o.a.s.s.ZkIndexSchemaReader Finished refreshing
schema in 30 ms
[junit4] 2> 2408329 INFO (qtp1276199975-16307) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 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> 2408330 INFO (qtp1113000480-16296) [n:127.0.0.1:53918_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> 2408331 INFO (qtp1113000480-16296) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 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> 2408332 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.s.ManagedIndexSchema Took 40.0ms for 3 replicas to apply schema update
version 1 for collection dv_coll
[junit4] 2> 2408333 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 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=147
[junit4] 2> 2408333 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.c.SolrCore
[dv_coll_shard3_replica1] CLOSING SolrCore
org.apache.solr.core.SolrCore@27b1385a
[junit4] 2> 2408333 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.dv_coll.shard3.replica1
[junit4] 2> 2408334 INFO (Thread-3509) [n:127.0.0.1:53919_solr ]
o.a.s.s.IndexSchema [dv_coll_shard3_replica1] Schema name=minimal
[junit4] 2> 2408348 INFO (Thread-3509) [n:127.0.0.1:53919_solr ]
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2408352 INFO (Thread-3509) [n:127.0.0.1:53919_solr ]
o.a.s.c.CoreContainer Reloading SolrCore 'dv_coll_shard3_replica1' using
configuration from collection dv_coll
[junit4] 2> 2408357 INFO (Thread-3509) [n:127.0.0.1:53919_solr c:dv_coll
s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.c.SolrCore
[[dv_coll_shard3_replica1] ] Opening new SolrCore at
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001/node2/dv_coll_shard3_replica1],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001/tempDir-001/node2/./dv_coll_shard3_replica1/data/]
[junit4] 2> 2408366 INFO
(TEST-DocValuesNotIndexedTest.testGroupingSorting-seed#[36B7C7B063946B0B]) [
] o.a.s.SolrTestCaseJ4 ###Starting testGroupingSorting
[junit4] 2> 2408375 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 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:53918/solr/dv_coll_shard2_replica1/&wt=javabin&version=2}{deleteByQuery=*:*
(-1557542117040979968)} 0 3
[junit4] 2> 2408377 INFO (qtp1113000480-16297) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 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:53918/solr/dv_coll_shard2_replica1/&wt=javabin&version=2}{deleteByQuery=*:*
(-1557542117039931392)} 0 5
[junit4] 2> 2408377 INFO (qtp1276199975-16307) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1]
o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr
path=/update
params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:53918/solr/dv_coll_shard2_replica1/&wt=javabin&version=2}{deleteByQuery=*:*
(-1557542117039931392)} 0 6
[junit4] 2> 2408378 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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={wt=javabin&version=2}{deleteByQuery=*:*
(-1557542117037834240)} 0 10
[junit4] 2> 2408379 INFO (Thread-3509) [n:127.0.0.1:53919_solr c:dv_coll
s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.u.CommitTracker Hard
AutoCommit: disabled
[junit4] 2> 2408379 INFO (Thread-3509) [n:127.0.0.1:53919_solr c:dv_coll
s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.u.CommitTracker Soft
AutoCommit: disabled
[junit4] 2> 2408379 INFO (Thread-3509) [n:127.0.0.1:53919_solr c:dv_coll
s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.s.SolrIndexSearcher
Opening [Searcher@453142b6[dv_coll_shard3_replica1] main]
[junit4] 2> 2408380 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 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> 2408380 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2408381 INFO (qtp1113000480-16298) [n:127.0.0.1:53918_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> 2408381 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@1d70f30[dv_coll_shard1_replica1]
main]
[junit4] 2> 2408382 INFO (qtp1113000480-16298) [n:127.0.0.1:53918_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> 2408382 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2408382 INFO
(searcherExecutor-8244-thread-1-processing-n:127.0.0.1:53919_solr
x:dv_coll_shard1_replica1 s:shard1 c:dv_coll r:core_node3)
[n:127.0.0.1:53919_solr c:dv_coll s:shard1 r:core_node3
x:dv_coll_shard1_replica1] o.a.s.c.SolrCore [dv_coll_shard1_replica1]
Registered new searcher Searcher@1d70f30[dv_coll_shard1_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2408382 INFO (qtp1113000480-16298) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@6e7cced2[dv_coll_shard2_replica1]
main]
[junit4] 2> 2408382 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 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:53919/solr/dv_coll_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 1
[junit4] 2> 2408382 INFO (qtp1276199975-16308) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 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> 2408382 INFO (qtp1276199975-16308) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2408382 INFO
(searcherExecutor-8243-thread-1-processing-n:127.0.0.1:53918_solr
x:dv_coll_shard2_replica1 s:shard2 c:dv_coll r:core_node4)
[n:127.0.0.1:53918_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@6e7cced2[dv_coll_shard2_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2408382 INFO (qtp1113000480-16298) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2408383 INFO (qtp1113000480-16298) [n:127.0.0.1:53918_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:53919/solr/dv_coll_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 2
[junit4] 2> 2408383 INFO (qtp1113000480-16296) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 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> 2408383 INFO (qtp1113000480-16296) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 x:dv_coll_shard4_replica1]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2408384 INFO (qtp1113000480-16296) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 x:dv_coll_shard4_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@6aad5317[dv_coll_shard4_replica1]
main]
[junit4] 2> 2408384 INFO (Thread-3509) [n:127.0.0.1:53919_solr c:dv_coll
s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.r.ManagedResourceStorage
Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2408384 INFO (qtp1113000480-16296) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 x:dv_coll_shard4_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2408384 INFO
(searcherExecutor-8246-thread-1-processing-n:127.0.0.1:53918_solr
x:dv_coll_shard4_replica1 s:shard4 c:dv_coll r:core_node1)
[n:127.0.0.1:53918_solr c:dv_coll s:shard4 r:core_node1
x:dv_coll_shard4_replica1] o.a.s.c.SolrCore [dv_coll_shard4_replica1]
Registered new searcher Searcher@6aad5317[dv_coll_shard4_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2408384 INFO (qtp1113000480-16296) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 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:53919/solr/dv_coll_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 1
[junit4] 2> 2408385 INFO (Thread-3509) [n:127.0.0.1:53919_solr c:dv_coll
s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.r.ManagedResourceStorage
Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2408385 INFO (Thread-3509) [n:127.0.0.1:53919_solr c:dv_coll
s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.s.ZkIndexSchemaReader
Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2408386 INFO (Thread-3509) [n:127.0.0.1:53919_solr c:dv_coll
s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.s.ZkIndexSchemaReader
Current schema version 1 is already the latest
[junit4] 2> 2408386 INFO (Thread-3509) [n:127.0.0.1:53919_solr c:dv_coll
s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.h.ReplicationHandler
Commits will be reserved for 10000
[junit4] 2> 2408386 INFO
(searcherExecutor-8268-thread-1-processing-n:127.0.0.1:53919_solr
x:dv_coll_shard3_replica1 s:shard3 c:dv_coll r:core_node2)
[n:127.0.0.1:53919_solr c:dv_coll s:shard3 r:core_node2
x:dv_coll_shard3_replica1] o.a.s.c.SolrCore [dv_coll_shard3_replica1]
Registered new searcher Searcher@453142b6[dv_coll_shard3_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2408386 INFO (qtp1276199975-16308) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2408387 INFO (qtp1276199975-16308) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 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:53919/solr/dv_coll_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 4
[junit4] 2> 2408387 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica1] webapp=/solr
path=/update
params={_stateVer_=dv_coll:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
0 8
[junit4] 2> 2408393 INFO (qtp1113000480-16299) [n:127.0.0.1:53918_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=[4
(1557542117058805760)]} 0 4
[junit4] 2> 2408395 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 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
(1557542117059854336)]} 0 4
[junit4] 2> 2408451 INFO (Thread-3509) [n:127.0.0.1:53919_solr c:dv_coll
s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.u.DefaultSolrCoreState
New IndexWriter is ready to be used.
[junit4] 2> 2408453 INFO (qtp1276199975-16301) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 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
(1557542117059854336), 3 (1557542117063000064)]} 0 64
[junit4] 2> 2408455 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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> 2408455 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 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> 2408455 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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@2f684653
[junit4] 2> 2408455 INFO (qtp1276199975-16308) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 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> 2408455 INFO (qtp1113000480-16295) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 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> 2408455 INFO (qtp1276199975-16308) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@4b0c9b2e
[junit4] 2> 2408455 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@204e25a6
[junit4] 2> 2408455 INFO (qtp1113000480-16295) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 x:dv_coll_shard4_replica1]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2408459 INFO (qtp1113000480-16295) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 x:dv_coll_shard4_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2408459 INFO (qtp1113000480-16295) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 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:53919/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 4
[junit4] 2> 2408466 INFO (Thread-3509) [n:127.0.0.1:53919_solr c:dv_coll
s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.s.SolrIndexSearcher
Opening [Searcher@5451e0e3[dv_coll_shard3_replica1] main]
[junit4] 2> 2408467 INFO (Thread-3509) [n:127.0.0.1:53919_solr c:dv_coll
s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.c.SolrCore config update
listener called for core dv_coll_shard1_replica1
[junit4] 2> 2408467 INFO
(searcherExecutor-8268-thread-1-processing-n:127.0.0.1:53919_solr
x:dv_coll_shard3_replica1 s:shard3 c:dv_coll r:core_node2)
[n:127.0.0.1:53919_solr c:dv_coll s:shard3 r:core_node2
x:dv_coll_shard3_replica1] o.a.s.c.SolrCore [dv_coll_shard3_replica1]
Registered new searcher Searcher@5451e0e3[dv_coll_shard3_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C1)))}
[junit4] 2> 2408498 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@43c56d3a[dv_coll_shard2_replica1]
main]
[junit4] 2> 2408499 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2408499 INFO
(searcherExecutor-8243-thread-1-processing-n:127.0.0.1:53918_solr
x:dv_coll_shard2_replica1 s:shard2 c:dv_coll r:core_node4)
[n:127.0.0.1:53918_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@43c56d3a[dv_coll_shard2_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C1)))}
[junit4] 2> 2408499 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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:53919/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 44
[junit4] 2> 2408515 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@4c4bd8da[dv_coll_shard1_replica1]
main]
[junit4] 2> 2408515 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2408515 INFO
(searcherExecutor-8244-thread-1-processing-n:127.0.0.1:53919_solr
x:dv_coll_shard1_replica1 s:shard1 c:dv_coll r:core_node3)
[n:127.0.0.1:53919_solr c:dv_coll s:shard1 r:core_node3
x:dv_coll_shard1_replica1] o.a.s.c.SolrCore [dv_coll_shard1_replica1]
Registered new searcher Searcher@4c4bd8da[dv_coll_shard1_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C1)))}
[junit4] 2> 2408516 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 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:53919/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 61
[junit4] 2> 2408517 INFO (qtp1276199975-16308) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@3f2ccaac[dv_coll_shard3_replica1]
main]
[junit4] 2> 2408517 INFO (qtp1276199975-16308) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2408517 INFO
(searcherExecutor-8263-thread-1-processing-n:127.0.0.1:53919_solr
x:dv_coll_shard3_replica1 s:shard3 c:dv_coll r:core_node2)
[n:127.0.0.1:53919_solr c:dv_coll s:shard3 r:core_node2
x:dv_coll_shard3_replica1] o.a.s.c.SolrCore [dv_coll_shard3_replica1]
Registered new searcher Searcher@3f2ccaac[dv_coll_shard3_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C1)
Uninverting(_1(7.0.0):C1)))}
[junit4] 2> 2408517 INFO (qtp1276199975-16308) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 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:53919/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 62
[junit4] 2> 2408517 INFO (qtp1276199975-16308) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.c.SolrCore
[dv_coll_shard3_replica1] CLOSING SolrCore
org.apache.solr.core.SolrCore@5f5b6715
[junit4] 2> 2408518 INFO (qtp1276199975-16308) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.dv_coll.shard3.replica1
[junit4] 2> 2408518 INFO (qtp1276199975-16307) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 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 64
[junit4] 2> 2408522 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_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&fl=id&shards.purpose=4&start=0&fsv=true&sort=intGSF+asc,id+asc&shard.url=http://127.0.0.1:53918/solr/dv_coll_shard2_replica1/&rows=100&version=2&q=*:*&NOW=1485387913890&isShard=true&wt=javabin}
hits=1 status=0 QTime=0
[junit4] 2> 2408523 INFO (qtp1113000480-16298) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 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&fl=id&shards.purpose=4&start=0&fsv=true&sort=intGSF+asc,id+asc&shard.url=http://127.0.0.1:53918/solr/dv_coll_shard4_replica1/&rows=100&version=2&q=*:*&NOW=1485387913890&isShard=true&wt=javabin}
hits=0 status=0 QTime=0
[junit4] 2> 2408523 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 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&fl=id&shards.purpose=4&start=0&fsv=true&sort=intGSF+asc,id+asc&shard.url=http://127.0.0.1:53919/solr/dv_coll_shard3_replica1/&rows=100&version=2&q=*:*&NOW=1485387913890&isShard=true&wt=javabin}
hits=1 status=0 QTime=0
[junit4] 2> 2408524 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 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&fl=id&shards.purpose=4&start=0&fsv=true&sort=intGSF+asc,id+asc&shard.url=http://127.0.0.1:53919/solr/dv_coll_shard1_replica1/&rows=100&version=2&q=*:*&NOW=1485387913890&isShard=true&wt=javabin}
hits=1 status=0 QTime=0
[junit4] 2> 2408526 INFO (qtp1113000480-16298) [n:127.0.0.1:53918_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=*:*&df=text&distrib=false&_stateVer_=dv_coll:3&shards.purpose=64&NOW=1485387913890&ids=4&isShard=true&shard.url=http://127.0.0.1:53918/solr/dv_coll_shard2_replica1/&rows=100&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 2408526 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1] o.a.s.c.S.Request
[dv_coll_shard1_replica1] webapp=/solr path=/select
params={q=*:*&df=text&distrib=false&_stateVer_=dv_coll:3&shards.purpose=64&NOW=1485387913890&ids=1&isShard=true&shard.url=http://127.0.0.1:53919/solr/dv_coll_shard1_replica1/&rows=100&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 2408526 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1] o.a.s.c.S.Request
[dv_coll_shard3_replica1] webapp=/solr path=/select
params={q=*:*&df=text&distrib=false&_stateVer_=dv_coll:3&shards.purpose=64&NOW=1485387913890&ids=2&isShard=true&shard.url=http://127.0.0.1:53919/solr/dv_coll_shard3_replica1/&rows=100&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 2408527 INFO (qtp1113000480-16297) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 x:dv_coll_shard4_replica1] o.a.s.c.S.Request
[dv_coll_shard4_replica1] webapp=/solr path=/select
params={q=*:*&_stateVer_=dv_coll:3&sort=intGSF+asc,id+asc&rows=100&wt=javabin&version=2}
hits=3 status=0 QTime=7
[junit4] 2> 2408528 INFO
(TEST-DocValuesNotIndexedTest.testGroupingSorting-seed#[36B7C7B063946B0B]) [
] o.a.s.SolrTestCaseJ4 ###Ending testGroupingSorting
[junit4] 2> NOTE: reproduce with: ant test
-Dtestcase=DocValuesNotIndexedTest -Dtests.method=testGroupingSorting
-Dtests.seed=36B7C7B063946B0B -Dtests.slow=true -Dtests.locale=en-US
-Dtests.timezone=Pacific/Enderbury -Dtests.asserts=true
-Dtests.file.encoding=US-ASCII
[junit4] FAILURE 0.20s J1 | DocValuesNotIndexedTest.testGroupingSorting <<<
[junit4] > Throwable #1: java.lang.AssertionError: Should have exactly 4
documents returned expected:<4> but was:<3>
[junit4] > at
__randomizedtesting.SeedInfo.seed([36B7C7B063946B0B:288FCFB81F3FD18B]:0)
[junit4] > at
org.apache.solr.cloud.DocValuesNotIndexedTest.checkSortOrder(DocValuesNotIndexedTest.java:259)
[junit4] > at
org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingSorting(DocValuesNotIndexedTest.java:244)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2408558 INFO
(TEST-DocValuesNotIndexedTest.testGroupingDocAbsent-seed#[36B7C7B063946B0B]) [
] o.a.s.SolrTestCaseJ4 ###Starting testGroupingDocAbsent
[junit4] 2> 2408562 INFO (qtp1113000480-16295) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@3f5d8bd1[dv_coll_shard2_replica1]
realtime]
[junit4] 2> 2408562 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@1c36232c[dv_coll_shard1_replica1]
realtime]
[junit4] 2> 2408563 INFO (qtp1113000480-16295) [n:127.0.0.1:53918_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:53918/solr/dv_coll_shard4_replica1/&wt=javabin&version=2}{deleteByQuery=*:*
(-1557542117237063680)} 0 3
[junit4] 2> 2408563 INFO (qtp1276199975-16301) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@454f76a7[dv_coll_shard3_replica1]
realtime]
[junit4] 2> 2408563 INFO (qtp1276199975-16303) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1]
o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr
path=/update
params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:53918/solr/dv_coll_shard4_replica1/&wt=javabin&version=2}{deleteByQuery=*:*
(-1557542117237063680)} 0 3
[junit4] 2> 2408563 INFO (qtp1276199975-16301) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 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:53918/solr/dv_coll_shard4_replica1/&wt=javabin&version=2}{deleteByQuery=*:*
(-1557542117237063680)} 0 3
[junit4] 2> 2408563 INFO (qtp1113000480-16299) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 x:dv_coll_shard4_replica1]
o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard4_replica1] webapp=/solr
path=/update params={wt=javabin&version=2}{deleteByQuery=*:*
(-1557542117237063680)} 0 5
[junit4] 2> 2408566 INFO (qtp1276199975-16307) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 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> 2408566 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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> 2408566 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 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> 2408566 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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@2f684653
[junit4] 2> 2408566 INFO (qtp1276199975-16307) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@204e25a6
[junit4] 2> 2408566 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@4b0c9b2e
[junit4] 2> 2408566 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 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> 2408566 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 x:dv_coll_shard4_replica1]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2408566 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@14cba9f9[dv_coll_shard2_replica1]
main]
[junit4] 2> 2408567 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 x:dv_coll_shard4_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2408567 INFO (qtp1113000480-16294) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 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:53919/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 0
[junit4] 2> 2408567 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_solr
c:dv_coll s:shard2 r:core_node4 x:dv_coll_shard2_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2408567 INFO
(searcherExecutor-8243-thread-1-processing-n:127.0.0.1:53918_solr
x:dv_coll_shard2_replica1 s:shard2 c:dv_coll r:core_node4)
[n:127.0.0.1:53918_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@14cba9f9[dv_coll_shard2_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2408567 INFO (qtp1276199975-16307) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@53bc3164[dv_coll_shard1_replica1]
main]
[junit4] 2> 2408568 INFO (qtp1276199975-16307) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2408568 INFO
(searcherExecutor-8244-thread-1-processing-n:127.0.0.1:53919_solr
x:dv_coll_shard1_replica1 s:shard1 c:dv_coll r:core_node3)
[n:127.0.0.1:53919_solr c:dv_coll s:shard1 r:core_node3
x:dv_coll_shard1_replica1] o.a.s.c.SolrCore [dv_coll_shard1_replica1]
Registered new searcher Searcher@53bc3164[dv_coll_shard1_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2408568 INFO (qtp1113000480-16292) [n:127.0.0.1:53918_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:53919/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 2
[junit4] 2> 2408568 INFO (qtp1276199975-16307) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 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:53919/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 3
[junit4] 2> 2408569 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@21174ffa[dv_coll_shard3_replica1]
main]
[junit4] 2> 2408569 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 x:dv_coll_shard3_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2408569 INFO
(searcherExecutor-8268-thread-1-processing-n:127.0.0.1:53919_solr
x:dv_coll_shard3_replica1 s:shard3 c:dv_coll r:core_node2)
[n:127.0.0.1:53919_solr c:dv_coll s:shard3 r:core_node2
x:dv_coll_shard3_replica1] o.a.s.c.SolrCore [dv_coll_shard3_replica1]
Registered new searcher Searcher@21174ffa[dv_coll_shard3_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2408569 INFO (qtp1276199975-16305) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 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:53919/solr/dv_coll_shard1_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 3
[junit4] 2> 2408570 INFO (qtp1276199975-16308) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1]
o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica1] webapp=/solr
path=/update
params={_stateVer_=dv_coll:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
0 4
[junit4] 2> 2408573 INFO (qtp1276199975-16304) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 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
(1557542117249646592)]} 0 2
[junit4] 2> 2408574 INFO (qtp1276199975-16306) [n:127.0.0.1:53919_solr
c:dv_coll s:shard3 r:core_node2 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
(1557542117250695168), 3 (1557542117252792320)]} 0 2
[junit4] 2> 2408574 INFO (qtp1113000480-16296) [n:127.0.0.1:53918_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=[4
(1557542117249646592)]} 0 3
[junit4] 2> 2408576 INFO (qtp1113000480-16298) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 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> 2408576 INFO (qtp1276199975-16301) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 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> 2408577 INFO (qtp1113000480-16298) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 x:dv_coll_shard4_replica1]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2408577 INFO (qtp1276199975-16301) [n:127.0.0.1:53919_solr
c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica1]
o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@204e25a6
[junit4] 2> 2408577 INFO (qtp1113000480-16297) [n:127.0.0.1:53918_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> 2408577 INFO (qtp1113000480-16298) [n:127.0.0.1:53918_solr
c:dv_coll s:shard4 r:core_node1 x:dv_coll_shard4_replica1]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2408577 INFO (q
[...truncated too long message...]
e_nodes]
[junit4] 2> 2410675 INFO (jetty-launcher-2861-thread-1) [ ]
o.a.s.c.Overseer Overseer
(id=97346381959790598-127.0.0.1:53919_solr-n_0000000000) closing
[junit4] 2> 2410675 INFO (jetty-launcher-2861-thread-2) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 2410675 INFO
(OverseerStateUpdate-97346381959790598-127.0.0.1:53919_solr-n_0000000000)
[n:127.0.0.1:53919_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:53919_solr
[junit4] 2> 2410675 INFO
(zkCallback-2872-thread-1-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (1)
[junit4] 2> 2410676 INFO (jetty-launcher-2861-thread-2) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@6417bf1d{/solr,null,UNAVAILABLE}
[junit4] 2> 2412178 WARN
(zkCallback-2872-thread-1-processing-n:127.0.0.1:53919_solr)
[n:127.0.0.1:53919_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 2412179 INFO (jetty-launcher-2861-thread-1) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 2412179 INFO (jetty-launcher-2861-thread-1) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@574b78af{/solr,null,UNAVAILABLE}
[junit4] 2> 2412201 INFO
(SUITE-DocValuesNotIndexedTest-seed#[36B7C7B063946B0B]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:53916 53916
[junit4] 2> 2416494 INFO (Thread-3490) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:53916 53916
[junit4] 2> 2419026 WARN (Thread-3490) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/configs/conf1/managed-schema
[junit4] 2> 4 /solr/configs/conf1
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 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> 7 /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> 2419027 INFO
(SUITE-DocValuesNotIndexedTest-seed#[36B7C7B063946B0B]-worker) [ ]
o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at:
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.DocValuesNotIndexedTest_36B7C7B063946B0B-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70):
{_version_=FSTOrd50, id=PostingsFormat(name=LuceneFixedGap)},
docValues:{floatField=DocValuesFormat(name=Lucene70),
doubleField=DocValuesFormat(name=Asserting),
intFieldMulti=DocValuesFormat(name=Lucene70),
boolFieldMulti=DocValuesFormat(name=Asserting),
floatGSL=DocValuesFormat(name=Lucene70),
longFieldMulti=DocValuesFormat(name=Memory),
intField=DocValuesFormat(name=Asserting),
boolField=DocValuesFormat(name=Lucene70),
stringFieldMulti=DocValuesFormat(name=Lucene70),
dateFieldMulti=DocValuesFormat(name=Memory),
longGSF=DocValuesFormat(name=Lucene70),
doubleFieldMulti=DocValuesFormat(name=Lucene70),
stringGSL=DocValuesFormat(name=Memory),
doubleGSF=DocValuesFormat(name=Asserting),
doubleGSL=DocValuesFormat(name=Memory),
stringGSF=DocValuesFormat(name=Asserting),
intGSL=DocValuesFormat(name=Asserting),
longField=DocValuesFormat(name=Lucene70),
dateField=DocValuesFormat(name=Lucene70),
dateGSF=DocValuesFormat(name=Lucene70), boolGSF=DocValuesFormat(name=Lucene70),
longGSL=DocValuesFormat(name=Lucene70), boolGSL=DocValuesFormat(name=Lucene70),
floatFieldMulti=DocValuesFormat(name=Asserting),
floatGSF=DocValuesFormat(name=Lucene70),
dateGSL=DocValuesFormat(name=Lucene70), intGSF=DocValuesFormat(name=Memory),
stringField=DocValuesFormat(name=Asserting)}, maxPointsInLeafNode=994,
maxMBSortInHeap=5.7251959539859705, sim=RandomSimilarity(queryNorm=true): {},
locale=en-US, timezone=Pacific/Enderbury
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_121
(64-bit)/cpus=3,threads=1,free=244125368,total=490733568
[junit4] 2> NOTE: All tests run in this JVM:
[TestSolrCloudWithKerberosAlt, DocValuesMissingTest, SolrIndexMetricsTest,
TestComplexPhraseQParserPlugin, VMParamsZkACLAndCredentialsProvidersTest,
SolrCLIZkUtilsTest, DistanceUnitsTest, TestScoreJoinQPScore,
TestSchemaSimilarityResource, TestBadConfig, SolrMetricsIntegrationTest,
TestCloudSchemaless, DeleteInactiveReplicaTest, TestImplicitCoreProperties,
TestBulkSchemaAPI, TestTrackingShardHandlerFactory, UpdateParamsTest,
AsyncCallRequestStatusResponseTest, SuggesterTest,
TestDynamicFieldCollectionResource, TestInitParams, BadIndexSchemaTest,
BasicFunctionalityTest, TestConfigSetImmutable, LukeRequestHandlerTest,
SolrMetricManagerTest, TestDFRSimilarityFactory, ShardSplitTest,
HdfsBasicDistributedZkTest, TestJoin, TestHdfsBackupRestoreCore,
EchoParamsTest, TestXmlQParserPlugin, StatsComponentTest, TestInitQParser,
TestManagedSchemaThreadSafety, OverseerRolesTest, TestSchemaNameResource,
DistributedFacetExistsSmallTest, DistributedIntervalFacetingTest,
TestQueryUtils, URLClassifyProcessorTest, TestSegmentSorting, RankQueryTest,
AnalyticsMergeStrategyTest, TestSolrConfigHandler, TestCrossCoreJoin,
CdcrBootstrapTest, CollectionsAPIDistributedZkTest,
TestFuzzyAnalyzedSuggestions, RegexBoostProcessorTest, DataDrivenBlockJoinTest,
CdcrVersionReplicationTest, ReturnFieldsTest, TestConfig,
TestClassicSimilarityFactory, TestLMJelinekMercerSimilarityFactory,
FullHLLTest, UUIDFieldTest, HdfsSyncSliceTest, DistributedTermsComponentTest,
TestTolerantUpdateProcessorCloud, HdfsNNFailoverTest, ForceLeaderTest,
TestComponentsName, TestJmxMonitoredMap, TestSolrXml,
MissingSegmentRecoveryTest, CoreAdminCreateDiscoverTest, AtomicUpdatesTest,
TestLMDirichletSimilarityFactory, SpellCheckComponentTest,
TestManagedStopFilterFactory, TestDistributedMissingSort,
LeaderInitiatedRecoveryOnShardRestartTest, TestBlendedInfixSuggestions,
RequestHandlersTest, DefaultValueUpdateProcessorTest,
DistributedSuggestComponentTest, TestRangeQuery, TestDistribIDF,
JsonLoaderTest, TestReversedWildcardFilterFactory, TestExpandComponent,
SignatureUpdateProcessorFactoryTest, TemplateUpdateProcessorTest,
DeleteNodeTest, HighlighterConfigTest, TestFreeTextSuggestions, TestRTimerTree,
TestStandardQParsers, BlockCacheTest, CollectionTooManyReplicasTest,
SpatialRPTFieldTypeTest, AnalysisErrorHandlingTest,
TestBackupRepositoryFactory, TestZkChroot,
HdfsTlogReplayBufferedWhileIndexingTest, ReplaceNodeTest,
ResponseLogComponentTest, ShowFileRequestHandlerTest, TestSolrCoreParser,
TestSolrQueryParserResource, TestSearchPerf, HLLUtilTest,
RestartWhileUpdatingTest, TestSQLHandler, TestLuceneMatchVersion,
QueryParsingTest, BasicAuthIntegrationTest, TermVectorComponentTest,
TestCloudDeleteByQuery, DistanceFunctionTest, MetricUtilsTest,
TestSolrCoreProperties, TestFoldingMultitermQuery,
TestCopyFieldCollectionResource, TestExceedMaxTermLength, TestTrieFacet,
TestSolrDeletionPolicy2, TestBlobHandler, TestCloudManagedSchema, TestTrie,
TestSolr4Spatial, TestSubQueryTransformerDistrib, SolrIndexSplitterTest,
TestSmileRequest, CdcrReplicationHandlerTest, PreAnalyzedFieldTest,
SolrInfoMBeanTest, TestOnReconnectListenerSupport,
TestEmbeddedSolrServerConstructors, SolrCoreCheckLockOnStartupTest,
DeleteShardTest, DistributedFacetPivotSmallTest, TestFieldCollectionResource,
TestReloadAndDeleteDocs, SuggestComponentTest, TestIndexSearcher, TestRecovery,
TestUtils, ResourceLoaderTest, TestFieldCacheSanityChecker,
TestRandomRequestDistribution, TestSystemIdResolver, ZkStateWriterTest,
HdfsRecoveryZkTest, SpellCheckCollatorTest, TestLeaderElectionWithEmptyReplica,
TestCryptoKeys, HighlighterMaxOffsetTest, SolrXmlInZkTest,
WordBreakSolrSpellCheckerTest, LeaderElectionIntegrationTest, ClusterStateTest,
TestCustomDocTransformer, TestFieldTypeCollectionResource, CloudMLTQParserTest,
OverseerTaskQueueTest, CurrencyFieldOpenExchangeTest, TestLockTree,
ReplicaListTransformerTest, HdfsLockFactoryTest, TestConfigSets,
RAMDirectoryFactoryTest, TestSlowCompositeReaderWrapper,
TestQuerySenderListener, SyncSliceTest, RecoveryZkTest, ClusterStateUpdateTest,
TestRandomFaceting, ZkSolrClientTest, ZkCLITest,
TermVectorComponentDistributedTest, TestRealTimeGet, TestStressVersions,
SolrCoreTest, SolrCmdDistributorTest, TestFunctionQuery, TestLazyCores,
SoftAutoCommitTest, CoreAdminHandlerTest, NoCacheHeaderTest,
TestPseudoReturnFields, FieldMutatingUpdateProcessorTest,
TestAtomicUpdateErrorCases, StatelessScriptUpdateProcessorFactoryTest,
CacheHeaderTest, TestWriterPerf, FileBasedSpellCheckerTest,
PathHierarchyTokenizerFactoryTest, FieldAnalysisRequestHandlerTest,
IndexSchemaRuntimeFieldTest, IndexSchemaTest,
UpdateRequestProcessorFactoryTest, TestPartialUpdateDeduplication,
TestPHPSerializedResponseWriter, CSVRequestHandlerTest, TestSolrIndexConfig,
CopyFieldTest, SolrIndexConfigTest, BadComponentTest, TestStressRecovery,
SolrTestCaseJ4Test, TestCursorMarkWithoutUniqueKey, TestHighlightDedupGrouping,
TestSimpleTrackingShardHandler, TestJettySolrRunner, ConnectionReuseTest,
ActionThrottleTest, AliasIntegrationTest, CdcrReplicationDistributedZkTest,
CollectionReloadTest, CollectionsAPISolrJTest, DeleteStatusTest,
DistribJoinFromCollectionTest, DistributedVersionInfoTest,
DocValuesNotIndexedTest]
[junit4] Completed [487/680 (1!)] on J1 in 16.13s, 4 tests, 1 failure <<<
FAILURES!
[...truncated 63069 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
