You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2016/12/27 17:28:54 UTC
[JENKINS] Lucene-Solr-6.x-Windows (64bit/jdk1.8.0_112) - Build #
650 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Windows/650/
Java: 64bit/jdk1.8.0_112 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.core.TestDynamicLoading.testDynamicLoading
Error Message:
Could not get expected value 'X val' for path 'x' full output: { "responseHeader":{ "status":0, "QTime":0}, "params":{"wt":"json"}, "context":{ "webapp":"/jna/w", "path":"/test1", "httpMethod":"GET"}, "class":"org.apache.solr.core.BlobStoreTestRequestHandler", "x":null}, from server: null
Stack Trace:
java.lang.AssertionError: Could not get expected value 'X val' for path 'x' full output: {
"responseHeader":{
"status":0,
"QTime":0},
"params":{"wt":"json"},
"context":{
"webapp":"/jna/w",
"path":"/test1",
"httpMethod":"GET"},
"class":"org.apache.solr.core.BlobStoreTestRequestHandler",
"x":null}, from server: null
at __randomizedtesting.SeedInfo.seed([A55ED02FB7A870E4:7D13FD784075D544]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.core.TestSolrConfigHandler.testForResponseElement(TestSolrConfigHandler.java:535)
at org.apache.solr.core.TestDynamicLoading.testDynamicLoading(TestDynamicLoading.java:232)
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 org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:992)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:811)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 12472 lines...]
[junit4] Suite: org.apache.solr.core.TestDynamicLoading
[junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\init-core-data-001
[junit4] 2> 2421500 INFO (SUITE-TestDynamicLoading-seed#[A55ED02FB7A870E4]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 2421501 INFO (SUITE-TestDynamicLoading-seed#[A55ED02FB7A870E4]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /jna/w
[junit4] 2> 2421504 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2421505 INFO (Thread-4842) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2421505 INFO (Thread-4842) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2421605 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.ZkTestServer start zk server on port:57264
[junit4] 2> 2421639 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractZkTestCase put C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 2421643 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractZkTestCase put C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4] 2> 2421647 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractZkTestCase put C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2421650 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractZkTestCase put C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 2421653 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractZkTestCase put C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 2421656 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractZkTestCase put C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4] 2> 2421659 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractZkTestCase put C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 2421662 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractZkTestCase put C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 2421664 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractZkTestCase put C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2421667 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractZkTestCase put C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 2421670 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractZkTestCase put C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 2421673 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15941311eb00001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2422360 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\control-001\cores\collection1
[junit4] 2> 2422364 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2422365 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2d630e6e{/jna/w,null,AVAILABLE}
[junit4] 2> 2422366 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@b44b832{HTTP/1.1,[http/1.1]}{127.0.0.1:57283}
[junit4] 2> 2422367 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.Server Started @2430945ms
[junit4] 2> 2422367 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\tempDir-001/control/data, hostContext=/jna/w, hostPort=57283, coreRootDirectory=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\control-001\cores}
[junit4] 2> 2422368 ERROR (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2422368 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.4.0
[junit4] 2> 2422368 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2422368 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2422368 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-27T16:50:56.138Z
[junit4] 2> 2422373 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 2422373 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\control-001\solr.xml
[junit4] 2> 2422391 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2422392 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57264/solr
[junit4] 2> 2422423 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:57283_jna%2Fw
[junit4] 2> 2422425 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.Overseer Overseer (id=97180546189230084-127.0.0.1:57283_jna%2Fw-n_0000000000) starting
[junit4] 2> 2422434 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57283_jna%2Fw
[junit4] 2> 2422438 INFO (zkCallback-11558-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2422505 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\control-001\cores
[junit4] 2> 2422506 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 2422510 INFO (OverseerStateUpdate-97180546189230084-127.0.0.1:57283_jna%2Fw-n_0000000000) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 2423546 WARN (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 2423548 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2423570 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 2423692 WARN (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2423696 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2423716 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 2423716 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\control-001\cores\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\control-001\cores\collection1\data\]
[junit4] 2> 2423716 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@25a38e4
[junit4] 2> 2423717 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=23.1650390625, floorSegmentMB=1.6708984375, forceMergeDeletesPctAllowed=7.849456302403331, segmentsPerTier=12.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2423721 WARN (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 2423740 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2423740 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2423744 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2423745 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2423746 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=863471685, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 2423754 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5318be9f[collection1] main]
[junit4] 2> 2423757 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2423759 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2423759 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2423760 INFO (searcherExecutor-11354-thread-1-processing-n:127.0.0.1:57283_jna%2Fw x:collection1 c:control_collection) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5318be9f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2423761 INFO (coreLoadExecutor-11353-thread-1-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw c:control_collection x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554888741388025856
[junit4] 2> 2423781 INFO (coreZkRegister-11346-thread-1-processing-n:127.0.0.1:57283_jna%2Fw x:collection1 c:control_collection) [n:127.0.0.1:57283_jna%2Fw c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2423782 INFO (coreZkRegister-11346-thread-1-processing-n:127.0.0.1:57283_jna%2Fw x:collection1 c:control_collection) [n:127.0.0.1:57283_jna%2Fw c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2423782 INFO (coreZkRegister-11346-thread-1-processing-n:127.0.0.1:57283_jna%2Fw x:collection1 c:control_collection) [n:127.0.0.1:57283_jna%2Fw c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:57283/jna/w/collection1/
[junit4] 2> 2423782 INFO (coreZkRegister-11346-thread-1-processing-n:127.0.0.1:57283_jna%2Fw x:collection1 c:control_collection) [n:127.0.0.1:57283_jna%2Fw c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2423782 INFO (coreZkRegister-11346-thread-1-processing-n:127.0.0.1:57283_jna%2Fw x:collection1 c:control_collection) [n:127.0.0.1:57283_jna%2Fw c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:57283/jna/w/collection1/ has no replicas
[junit4] 2> 2423797 INFO (coreZkRegister-11346-thread-1-processing-n:127.0.0.1:57283_jna%2Fw x:collection1 c:control_collection) [n:127.0.0.1:57283_jna%2Fw c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:57283/jna/w/collection1/ shard1
[junit4] 2> 2423951 INFO (coreZkRegister-11346-thread-1-processing-n:127.0.0.1:57283_jna%2Fw x:collection1 c:control_collection) [n:127.0.0.1:57283_jna%2Fw c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2424208 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2424210 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:57264/solr ready
[junit4] 2> 2424212 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 2424846 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-1-001\cores\collection1
[junit4] 2> 2424848 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-1-001
[junit4] 2> 2424849 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2424850 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5385cb5b{/jna/w,null,AVAILABLE}
[junit4] 2> 2424851 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7e3b616d{HTTP/1.1,[http/1.1]}{127.0.0.1:57310}
[junit4] 2> 2424852 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.Server Started @2433430ms
[junit4] 2> 2424852 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/jna/w, hostPort=57310, coreRootDirectory=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-1-001\cores}
[junit4] 2> 2424852 ERROR (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2424852 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.4.0
[junit4] 2> 2424853 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2424853 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2424853 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-27T16:50:58.623Z
[junit4] 2> 2424858 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 2424858 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-1-001\solr.xml
[junit4] 2> 2424877 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2424877 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57264/solr
[junit4] 2> 2424894 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2424901 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57310_jna%2Fw
[junit4] 2> 2424904 INFO (zkCallback-11562-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2424904 INFO (zkCallback-11558-thread-2-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2424906 INFO (zkCallback-11567-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2424997 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-1-001\cores
[junit4] 2> 2424997 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 2425001 INFO (OverseerStateUpdate-97180546189230084-127.0.0.1:57283_jna%2Fw-n_0000000000) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
[junit4] 2> 2426028 WARN (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 2426029 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2426048 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 2426177 WARN (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2426179 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2426203 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2426204 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-1-001\cores\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-1-001\cores\collection1\data\]
[junit4] 2> 2426205 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@25a38e4
[junit4] 2> 2426213 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=23.1650390625, floorSegmentMB=1.6708984375, forceMergeDeletesPctAllowed=7.849456302403331, segmentsPerTier=12.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2426226 WARN (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 2426255 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2426255 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2426257 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2426257 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2426262 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=863471685, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 2426264 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@75c83cf7[collection1] main]
[junit4] 2> 2426267 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2426268 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2426269 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2426271 INFO (searcherExecutor-11365-thread-1-processing-n:127.0.0.1:57310_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@75c83cf7[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2426271 INFO (coreLoadExecutor-11364-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554888744019951616
[junit4] 2> 2426294 INFO (coreZkRegister-11359-thread-1-processing-n:127.0.0.1:57310_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57310_jna%2Fw c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2426294 INFO (coreZkRegister-11359-thread-1-processing-n:127.0.0.1:57310_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57310_jna%2Fw c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2426294 INFO (coreZkRegister-11359-thread-1-processing-n:127.0.0.1:57310_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57310_jna%2Fw c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:57310/jna/w/collection1/
[junit4] 2> 2426294 INFO (coreZkRegister-11359-thread-1-processing-n:127.0.0.1:57310_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57310_jna%2Fw c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2426294 INFO (coreZkRegister-11359-thread-1-processing-n:127.0.0.1:57310_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57310_jna%2Fw c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:57310/jna/w/collection1/ has no replicas
[junit4] 2> 2426306 INFO (coreZkRegister-11359-thread-1-processing-n:127.0.0.1:57310_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57310_jna%2Fw c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:57310/jna/w/collection1/ shard2
[junit4] 2> 2426460 INFO (coreZkRegister-11359-thread-1-processing-n:127.0.0.1:57310_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57310_jna%2Fw c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2427085 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-2-001\cores\collection1
[junit4] 2> 2427089 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-2-001
[junit4] 2> 2427089 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2427091 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@55d72e5a{/jna/w,null,AVAILABLE}
[junit4] 2> 2427092 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@669878f4{HTTP/1.1,[http/1.1]}{127.0.0.1:57335}
[junit4] 2> 2427092 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.Server Started @2435669ms
[junit4] 2> 2427092 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\tempDir-001/jetty2, solrconfig=solrconfig.xml, hostContext=/jna/w, hostPort=57335, coreRootDirectory=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-2-001\cores}
[junit4] 2> 2427092 ERROR (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2427093 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.4.0
[junit4] 2> 2427093 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2427093 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2427093 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-27T16:51:00.863Z
[junit4] 2> 2427114 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 2427114 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-2-001\solr.xml
[junit4] 2> 2427130 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2427131 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57264/solr
[junit4] 2> 2427137 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15941311eb0000a, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2427149 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2427157 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57335_jna%2Fw
[junit4] 2> 2427160 INFO (zkCallback-11562-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2427160 INFO (zkCallback-11558-thread-2-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2427161 INFO (zkCallback-11567-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2427161 INFO (zkCallback-11573-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2427433 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-2-001\cores
[junit4] 2> 2427433 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 2427436 INFO (OverseerStateUpdate-97180546189230084-127.0.0.1:57283_jna%2Fw-n_0000000000) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 2428458 WARN (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 2428460 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2428483 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 2428611 WARN (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2428613 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2428641 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2428641 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-2-001\cores\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-2-001\cores\collection1\data\]
[junit4] 2> 2428641 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@25a38e4
[junit4] 2> 2428658 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=23.1650390625, floorSegmentMB=1.6708984375, forceMergeDeletesPctAllowed=7.849456302403331, segmentsPerTier=12.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2428667 WARN (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 2428694 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2428694 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2428697 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2428697 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2428697 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=863471685, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 2428707 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5d62b3fb[collection1] main]
[junit4] 2> 2428710 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2428711 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2428711 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2428714 INFO (searcherExecutor-11376-thread-1-processing-n:127.0.0.1:57335_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5d62b3fb[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2428714 INFO (coreLoadExecutor-11375-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554888746581622784
[junit4] 2> 2428724 INFO (coreZkRegister-11370-thread-1-processing-n:127.0.0.1:57335_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57335_jna%2Fw c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2428724 INFO (coreZkRegister-11370-thread-1-processing-n:127.0.0.1:57335_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57335_jna%2Fw c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2428724 INFO (coreZkRegister-11370-thread-1-processing-n:127.0.0.1:57335_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57335_jna%2Fw c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:57335/jna/w/collection1/
[junit4] 2> 2428724 INFO (coreZkRegister-11370-thread-1-processing-n:127.0.0.1:57335_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57335_jna%2Fw c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2428724 INFO (coreZkRegister-11370-thread-1-processing-n:127.0.0.1:57335_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57335_jna%2Fw c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:57335/jna/w/collection1/ has no replicas
[junit4] 2> 2428733 INFO (coreZkRegister-11370-thread-1-processing-n:127.0.0.1:57335_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57335_jna%2Fw c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:57335/jna/w/collection1/ shard1
[junit4] 2> 2428895 INFO (coreZkRegister-11370-thread-1-processing-n:127.0.0.1:57335_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57335_jna%2Fw c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2429500 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-3-001\cores\collection1
[junit4] 2> 2429504 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-3-001
[junit4] 2> 2429504 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2429506 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@9e7b1d0{/jna/w,null,AVAILABLE}
[junit4] 2> 2429507 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@693b1e38{HTTP/1.1,[http/1.1]}{127.0.0.1:57366}
[junit4] 2> 2429508 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.Server Started @2438086ms
[junit4] 2> 2429508 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\tempDir-001/jetty3, solrconfig=solrconfig.xml, hostContext=/jna/w, hostPort=57366, coreRootDirectory=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-3-001\cores}
[junit4] 2> 2429508 ERROR (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2429508 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.4.0
[junit4] 2> 2429508 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2429509 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2429509 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-27T16:51:03.279Z
[junit4] 2> 2429513 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 2429514 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-3-001\solr.xml
[junit4] 2> 2429531 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2429531 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57264/solr
[junit4] 2> 2429548 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57366_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 2429555 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57366_jna%2Fw ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57366_jna%2Fw
[junit4] 2> 2429557 INFO (zkCallback-11562-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2429558 INFO (zkCallback-11567-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2429558 INFO (zkCallback-11558-thread-5-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2429557 INFO (zkCallback-11573-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2429559 INFO (zkCallback-11579-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2429617 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57366_jna%2Fw ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-3-001\cores
[junit4] 2> 2429617 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57366_jna%2Fw ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 2429621 INFO (OverseerStateUpdate-97180546189230084-127.0.0.1:57283_jna%2Fw-n_0000000000) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
[junit4] 2> 2430637 WARN (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 2430637 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2430674 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 2430779 WARN (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2430801 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2430820 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2430820 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-3-001\cores\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-3-001\cores\collection1\data\]
[junit4] 2> 2430820 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@25a38e4
[junit4] 2> 2430822 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=23.1650390625, floorSegmentMB=1.6708984375, forceMergeDeletesPctAllowed=7.849456302403331, segmentsPerTier=12.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2430828 WARN (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 2430853 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2430853 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2430855 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2430855 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2430856 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=863471685, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 2430856 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3e146389[collection1] main]
[junit4] 2> 2430859 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2430859 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2430859 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2430862 INFO (searcherExecutor-11387-thread-1-processing-n:127.0.0.1:57366_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3e146389[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2430862 INFO (coreLoadExecutor-11386-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554888748833964032
[junit4] 2> 2430880 INFO (coreZkRegister-11381-thread-1-processing-n:127.0.0.1:57366_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57366_jna%2Fw c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.ZkController Core needs to recover:collection1
[junit4] 2> 2430885 INFO (updateExecutor-11576-thread-1-processing-n:127.0.0.1:57366_jna%2Fw x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:57366_jna%2Fw c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 2430886 INFO (recoveryExecutor-11577-thread-1-processing-n:127.0.0.1:57366_jna%2Fw x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:57366_jna%2Fw c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 2430886 INFO (recoveryExecutor-11577-thread-1-processing-n:127.0.0.1:57366_jna%2Fw x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:57366_jna%2Fw c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 2430886 INFO (recoveryExecutor-11577-thread-1-processing-n:127.0.0.1:57366_jna%2Fw x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:57366_jna%2Fw c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
[junit4] 2> 2430886 INFO (recoveryExecutor-11577-thread-1-processing-n:127.0.0.1:57366_jna%2Fw x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:57366_jna%2Fw c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 2430886 INFO (recoveryExecutor-11577-thread-1-processing-n:127.0.0.1:57366_jna%2Fw x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:57366_jna%2Fw c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [http://127.0.0.1:57310/jna/w/collection1/] and I am [http://127.0.0.1:57366/jna/w/collection1/]
[junit4] 2> 2430889 INFO (recoveryExecutor-11577-thread-1-processing-n:127.0.0.1:57366_jna%2Fw x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:57366_jna%2Fw c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:57310/jna/w]; [WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:57366_jna%252Fw&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 2430899 INFO (qtp977902003-49657) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 2430905 INFO (qtp977902003-49657) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 (shard2 of collection1) have state: recovering
[junit4] 2> 2430905 INFO (qtp977902003-49657) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard2, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:57366_jna%2Fw, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"http://127.0.0.1:57366/jna/w","node_name":"127.0.0.1:57366_jna%2Fw","state":"down"}
[junit4] 2> 2431617 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-4-001\cores\collection1
[junit4] 2> 2431620 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 4 in directory C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-4-001
[junit4] 2> 2431620 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2431621 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@176cd3a1{/jna/w,null,AVAILABLE}
[junit4] 2> 2431622 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@49561fac{HTTP/1.1,[http/1.1]}{127.0.0.1:57390}
[junit4] 2> 2431623 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.e.j.s.Server Started @2440201ms
[junit4] 2> 2431623 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\tempDir-001/jetty4, solrconfig=solrconfig.xml, hostContext=/jna/w, hostPort=57390, coreRootDirectory=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-4-001\cores}
[junit4] 2> 2431624 ERROR (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2431624 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.4.0
[junit4] 2> 2431624 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2431624 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2431624 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-27T16:51:05.394Z
[junit4] 2> 2431629 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 2431631 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-4-001\solr.xml
[junit4] 2> 2431646 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2431647 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57264/solr
[junit4] 2> 2431664 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57390_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 2431672 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57390_jna%2Fw ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57390_jna%2Fw
[junit4] 2> 2431673 INFO (zkCallback-11562-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2431674 INFO (zkCallback-11573-thread-1-processing-n:127.0.0.1:57335_jna%2Fw) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2431674 INFO (zkCallback-11558-thread-5-processing-n:127.0.0.1:57283_jna%2Fw) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2431675 INFO (zkCallback-11586-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2431675 INFO (zkCallback-11579-thread-1-processing-n:127.0.0.1:57366_jna%2Fw) [n:127.0.0.1:57366_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2431676 INFO (zkCallback-11567-thread-1-processing-n:127.0.0.1:57310_jna%2Fw) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2431728 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57390_jna%2Fw ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-4-001\cores
[junit4] 2> 2431728 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [n:127.0.0.1:57390_jna%2Fw ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 2431730 INFO (OverseerStateUpdate-97180546189230084-127.0.0.1:57283_jna%2Fw-n_0000000000) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 2431905 INFO (qtp977902003-49657) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard2, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:57366_jna%2Fw, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"http://127.0.0.1:57366/jna/w","node_name":"127.0.0.1:57366_jna%2Fw","state":"recovering"}
[junit4] 2> 2431905 INFO (qtp977902003-49657) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 2431905 INFO (qtp977902003-49657) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:57366_jna%252Fw&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node3&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1006
[junit4] 2> 2432752 WARN (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 2432754 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2432771 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 2432897 WARN (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2432899 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2432920 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2432920 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-4-001\cores\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001\shard-4-001\cores\collection1\data\]
[junit4] 2> 2432920 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@25a38e4
[junit4] 2> 2432921 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=23.1650390625, floorSegmentMB=1.6708984375, forceMergeDeletesPctAllowed=7.849456302403331, segmentsPerTier=12.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2432930 WARN (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 2432956 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2432956 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2432958 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2432958 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2432958 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=863471685, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 2432959 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@747c502[collection1] main]
[junit4] 2> 2432961 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2432961 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2432961 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2432963 INFO (searcherExecutor-11398-thread-1-processing-n:127.0.0.1:57390_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@747c502[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2432963 INFO (coreLoadExecutor-11397-thread-1-processing-n:127.0.0.1:57390_jna%2Fw) [n:127.0.0.1:57390_jna%2Fw c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554888751037022208
[junit4] 2> 2432969 INFO (coreZkRegister-11392-thread-1-processing-n:127.0.0.1:57390_jna%2Fw x:collection1 c:collection1) [n:127.0.0.1:57390_jna%2Fw c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.ZkController Core needs to recover:collection1
[junit4] 2> 2432970 INFO (updateExecutor-11583-thread-1-processing-n:127.0.0.1:57390_jna%2Fw x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57390_jna%2Fw c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 2432970 INFO (recoveryExecutor-11584-thread-1-processing-n:127.0.0.1:57390_jna%2Fw x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57390_jna%2Fw c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 2432971 INFO (recoveryExecutor-11584-thread-1-processing-n:127.0.0.1:57390_jna%2Fw x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57390_jna%2Fw c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 2432971 INFO (recoveryExecutor-11584-thread-1-processing-n:127.0.0.1:57390_jna%2Fw x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57390_jna%2Fw c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
[junit4] 2> 2432971 INFO (recoveryExecutor-11584-thread-1-processing-n:127.0.0.1:57390_jna%2Fw x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57390_jna%2Fw c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 2432971 INFO (recoveryExecutor-11584-thread-1-processing-n:127.0.0.1:57390_jna%2Fw x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57390_jna%2Fw c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [http://127.0.0.1:57335/jna/w/collection1/] and I am [http://127.0.0.1:57390/jna/w/collection1/]
[junit4] 2> 2432975 INFO (recoveryExecutor-11584-thread-1-processing-n:127.0.0.1:57390_jna%2Fw x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57390_jna%2Fw c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:57335/jna/w]; [WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:57390_jna%252Fw&coreNodeName=core_node4&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 2432981 INFO (qtp1747048194-49685) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node4, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 2432983 INFO (qtp1747048194-49685) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
[junit4] 2> 2432983 INFO (qtp1747048194-49685) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:57390_jna%2Fw, coreNodeName=core_node4, onlyIfActiveCheckResult=false, nodeProps: core_node4:{"core":"collection1","base_url":"http://127.0.0.1:57390/jna/w","node_name":"127.0.0.1:57390_jna%2Fw","state":"down"}
[junit4] 2> 2433229 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDynamicLoading
[junit4] 2> 2433238 INFO (TEST-TestDynamicLoading.testDynamicLoading-seed#[A55ED02FB7A870E4]) [ ] o.a.s.c.TestSolrConfigHandler going to send config command. path /config?wt=json , payload:
[junit4] 2> 2433247 INFO (qtp680937698-49752) [n:127.0.0.1:57390_jna%2Fw c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.h.SolrConfigHandler Executed config commands successfully and persisted to ZK [{"add-runtimelib":{
[junit4] 2> "name":"colltest",
[junit4] 2> "version":1}}]
[junit4] 2> 2433247 INFO (qtp680937698-49752) [n:127.0.0.1:57390_jna%2Fw c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.h.SolrConfigHandler Waiting up to 30 secs for 2 replicas to set the property overlay to be of version 0 for collection collection1
[junit4] 2> 2433251 INFO (Thread-4895) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.c.SolrCore config update listener called for core collection1
[junit4] 2> 2433252 INFO (Thread-4897) [n:127.0.0.1:57366_jna%2Fw ] o.a.s.c.SolrCore config update listener called for core collection1
[junit4] 2> 2433252 INFO (Thread-4895) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.c.SolrCore core reload collection1
[junit4] 2> 2433253 INFO (Thread-4896) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.SolrCore config update listener called for core collection1
[junit4] 2> 2433253 INFO (Thread-4898) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.c.SolrCore config update listener called for core collection1
[junit4] 2> 2433253 INFO (Thread-4897) [n:127.0.0.1:57366_jna%2Fw ] o.a.s.c.SolrCore core reload collection1
[junit4] 2> 2433254 INFO (Thread-4896) [n:127.0.0.1:57283_jna%2Fw ] o.a.s.c.SolrCore core reload collection1
[junit4] 2> 2433255 INFO (Thread-4898) [n:127.0.0.1:57310_jna%2Fw ] o.a.s.c.SolrCore core reload collection1
[junit4] 2> 2433255 INFO (Thread-4899) [n:127.0.0.1:57390_jna%2Fw ] o.a.s.c.SolrCore config update listener called for core collection1
[junit4] 2> 2433256 INFO (Thread-4899) [n:127.0.0.1:57390_jna%2Fw ] o.a.s.c.SolrCore core reload collection1
[junit4] 2> 2433257 INFO (solrHandlerExecutor-11403-thread-2-processing-n:127.0.0.1:57390_jna%2Fw x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57390_jna%2Fw c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.h.SolrConfigHandler Time elapsed : 0 secs, maxWait 30
[junit4] 2> 2433257 INFO (solrHandlerExecutor-11403-thread-1-processing-n:127.0.0.1:57390_jna%2Fw x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:57390_jna%2Fw c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.h.SolrConfigHandler Time elapsed : 0 secs, maxWait 30
[junit4] 2> 2433266 WARN (Thread-4895) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 2433267 INFO (Thread-4895) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2433290 INFO (Thread-4895) [n:127.0.0.1:57335_jna%2Fw ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 2433366 INFO (qtp977902003-49661) [n:127.0.0.1:57310_jna%2Fw c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.h.SolrConfigHandler expecting overlay version 0 but my version is -1
[junit4] 2> 2433366 INFO (qtp977902003-49661) [n:127.0.0.1:57310_jna%2Fw c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.S.Request [collection1] webapp=/jna/w p
[...truncated too long message...]
Dtests.slow=true -Dtests.locale=ar-DZ -Dtests.timezone=Asia/Vladivostok -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 50.1s J1 | TestDynamicLoading.testDynamicLoading <<<
[junit4] > Throwable #1: java.lang.AssertionError: Could not get expected value 'X val' for path 'x' full output: {
[junit4] > "responseHeader":{
[junit4] > "status":0,
[junit4] > "QTime":0},
[junit4] > "params":{"wt":"json"},
[junit4] > "context":{
[junit4] > "webapp":"/jna/w",
[junit4] > "path":"/test1",
[junit4] > "httpMethod":"GET"},
[junit4] > "class":"org.apache.solr.core.BlobStoreTestRequestHandler",
[junit4] > "x":null}, from server: null
[junit4] > at __randomizedtesting.SeedInfo.seed([A55ED02FB7A870E4:7D13FD784075D544]:0)
[junit4] > at org.apache.solr.core.TestSolrConfigHandler.testForResponseElement(TestSolrConfigHandler.java:535)
[junit4] > at org.apache.solr.core.TestDynamicLoading.testDynamicLoading(TestDynamicLoading.java:232)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:992)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2471556 INFO (SUITE-TestDynamicLoading-seed#[A55ED02FB7A870E4]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.core.TestDynamicLoading_A55ED02FB7A870E4-001
[junit4] 2> Dec 27, 2016 4:51:45 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {blobName=PostingsFormat(name=LuceneFixedGap), size=PostingsFormat(name=LuceneVarGapDocFreqInterval), _version_=FST50, id=Lucene50(blocksize=128), version=FST50, md5=PostingsFormat(name=LuceneFixedGap), timestamp=PostingsFormat(name=LuceneFixedGap)}, docValues:{}, maxPointsInLeafNode=534, maxMBSortInHeap=6.628433254746257, sim=RandomSimilarity(queryNorm=false,coord=yes): {}, locale=ar-DZ, timezone=Asia/Vladivostok
[junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 1.8.0_112 (64-bit)/cpus=3,threads=1,free=260161824,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestFieldCacheWithThreads, TestCoreDiscovery, TestLMDirichletSimilarityFactory, TestRestoreCore, ZkSolrClientTest, TestSQLHandlerNonCloud, TestComplexPhraseQParserPlugin, DeleteShardTest, UpdateRequestProcessorFactoryTest, TestUseDocValuesAsStored2, TestImpersonationWithHadoopAuth, ConjunctionSolrSpellCheckerTest, TolerantUpdateProcessorTest, RAMDirectoryFactoryTest, NotRequiredUniqueKeyTest, StatsReloadRaceTest, ExternalFileFieldSortTest, TestSystemIdResolver, TestCloudPseudoReturnFields, AliasIntegrationTest, DistributedVersionInfoTest, TestBinaryResponseWriter, CoreAdminHandlerTest, OverseerModifyCollectionTest, TestReloadDeadlock, CdcrReplicationHandlerTest, TestFreeTextSuggestions, TestBulkSchemaConcurrent, TestStandardQParsers, TestDownShardTolerantSearch, RulesTest, TestFieldResource, SignatureUpdateProcessorFactoryTest, ConnectionReuseTest, HdfsBasicDistributedZk2Test, DistributedFacetPivotWhiteBoxTest, TestFieldSortValues, SolrCloudExampleTest, NoCacheHeaderTest, TestManagedSchemaAPI, TestConfigSetsAPI, RequestHandlersTest, HLLUtilTest, OverseerStatusTest, TestDocSet, TestValueSourceCache, TestDFRSimilarityFactory, AutoCommitTest, MetricUtilsTest, TestRequestForwarding, LeaderInitiatedRecoveryOnShardRestartTest, TestFoldingMultitermQuery, DistribJoinFromCollectionTest, TestAuthenticationFramework, EnumFieldTest, ConfigSetsAPITest, SpellingQueryConverterTest, FullHLLTest, TestSolrQueryParser, ExitableDirectoryReaderTest, TestDistributedStatsComponentCardinality, TestSolrDeletionPolicy2, EchoParamsTest, QueryResultKeyTest, CircularListTest, LeaderElectionContextKeyTest, DateRangeFieldTest, TestTrie, ClassificationUpdateProcessorFactoryTest, QueryParsingTest, HdfsThreadLeakTest, HdfsCollectionsAPIDistributedZkTest, BasicZkTest, URLClassifyProcessorTest, RemoteQueryErrorTest, CollectionsAPISolrJTest, TestManagedResource, SolrCoreCheckLockOnStartupTest, RequestLoggingTest, DocExpirationUpdateProcessorFactoryTest, TestSchemaResource, GraphQueryTest, CdcrBootstrapTest, TestRecovery, JSONWriterTest, DistributedTermsComponentTest, TestLRUStatsCache, AddSchemaFieldsUpdateProcessorFactoryTest, CollectionReloadTest, StatsComponentTest, SecurityConfHandlerTest, InfoHandlerTest, DistribCursorPagingTest, TestFiltering, TestCloudInspectUtil, SolrIndexSplitterTest, TestSolrDynamicMBean, SuggesterWFSTTest, LeaderFailureAfterFreshStartTest, TestDefaultStatsCache, TestSolrCoreProperties, SuggesterTest, CopyFieldTest, TestConfig, TestCollationFieldDocValues, TestGraphTermsQParserPlugin, TestIndexingPerformance, TestSearchPerf, TestPKIAuthenticationPlugin, TestRandomFaceting, DeleteNodeTest, CreateCollectionCleanupTest, TestQueryUtils, TestRangeQuery, ZkStateReaderTest, LukeRequestHandlerTest, ShufflingReplicaListTransformerTest, SuggestComponentContextFilterQueryTest, TestChildDocTransformer, FullSolrCloudDistribCmdsTest, TestOverriddenPrefixQueryForCustomFieldType, CloudMLTQParserTest, FileBasedSpellCheckerTest, TestMiniSolrCloudCluster, TestSolr4Spatial2, HighlighterConfigTest, TestXmlQParserPlugin, HdfsRestartWhileUpdatingTest, TestHdfsCloudBackupRestore, TestClusterProperties, TestRealTimeGet, TestLMJelinekMercerSimilarityFactory, TermVectorComponentTest, DistributedIntervalFacetingTest, BasicFunctionalityTest, UpdateParamsTest, CollectionsAPIDistributedZkTest, BlockJoinFacetRandomTest, TestLocalFSCloudBackupRestore, FacetPivotSmallTest, TestExactSharedStatsCache, TestSolrQueryParserDefaultOperatorResource, TestRandomFlRTGCloud, SolrCoreMetricManagerTest, ReplicationFactorTest, HdfsRecoverLeaseTest, SuggesterTSTTest, TestOrdValues, SortSpecParsingTest, ParsingFieldUpdateProcessorsTest, TestCodecSupport, SimpleCollectionCreateDeleteTest, DebugComponentTest, DistanceUnitsTest, HdfsChaosMonkeyNothingIsSafeTest, PKIAuthenticationIntegrationTest, TestTrieFacet, TestSha256AuthenticationProvider, TestRestManager, TemplateUpdateProcessorTest, JavabinLoaderTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, UnloadDistributedZkTest, SyncSliceTest, OpenCloseCoreStressTest, LeaderElectionIntegrationTest, RecoveryZkTest, ClusterStateUpdateTest, LeaderElectionTest, TestZkChroot, ZkCLITest, ShardRoutingCustomTest, TestDistributedGrouping, TestFaceting, TestHashPartitioner, TermVectorComponentDistributedTest, TestStressReorder, TestJoin, TestReload, HardAutoCommitTest, SimpleFacetsTest, TestSolr4Spatial, SpellCheckComponentTest, TestGroupingSearch, SolrCmdDistributorTest, QueryElevationComponentTest, BadIndexSchemaTest, ConvertedLegacyTest, TestFunctionQuery, TestLazyCores, DirectUpdateHandlerTest, TestBadConfig, TestIndexSearcher, HighlighterTest, ShowFileRequestHandlerTest, CurrencyFieldOpenExchangeTest, CurrencyFieldXmlFileTest, TestExtendedDismaxParser, SpellCheckCollatorTest, SuggesterFSTTest, SpatialFilterTest, PolyFieldTest, WordBreakSolrSpellCheckerTest, SchemaVersionSpecificBehaviorTest, FieldMutatingUpdateProcessorTest, TestAtomicUpdateErrorCases, TestWordDelimiterFilterFactory, DirectUpdateHandlerOptimizeTest, DefaultValueUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest, SortByFunctionTest, DistanceFunctionTest, TestSolrDeletionPolicy1, SolrInfoMBeanTest, XsltUpdateRequestHandlerTest, CacheHeaderTest, TestWriterPerf, TestReversedWildcardFilterFactory, TestQueryTypes, PrimitiveFieldTypeTest, TestOmitPositions, XmlUpdateRequestHandlerTest, PathHierarchyTokenizerFactoryTest, FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, LoggingHandlerTest, RegexBoostProcessorTest, IndexSchemaTest, TestJmxIntegration, TestCollationField, ReturnFieldsTest, JSONWriterTest, MBeansHandlerTest, TestAnalyzedSuggestions, JsonLoaderTest, BinaryUpdateRequestHandlerTest, TestPHPSerializedResponseWriter, CSVRequestHandlerTest, TestComponentsName, SearchHandlerTest, TestLFUCache, SOLR749Test, TestQuerySenderListener, AlternateDirectoryTest, TestQuerySenderNoQuery, ResponseLogComponentTest, SolrIndexConfigTest, TestMergePolicyConfig, OutputWriterTest, TestPostingsSolrHighlighter, TestLuceneMatchVersion, SpellPossibilityIteratorTest, TestXIncludeConfig, TestIBSimilarityFactory, TimeZoneUtilsTest, ResourceLoaderTest, TestFastOutputStream, PluginInfoTest, DateMathParserTest, PrimUtilsTest, TestSuggestSpellingConverter, TestSolrJ, TestLRUCache, TestDocumentBuilder, SystemInfoHandlerTest, UUIDFieldTest, DistributedMLTComponentTest, TestCrossCoreJoin, TestDistributedMissingSort, BaseCdcrDistributedZkTest, CdcrRequestHandlerTest, CdcrVersionReplicationTest, CollectionsAPIAsyncDistributedZkTest, DeleteInactiveReplicaTest, DeleteReplicaTest, MigrateRouteKeyTest, MultiThreadedOCPTest, OutOfBoxZkACLAndCredentialsProvidersTest, OverriddenZkACLAndCredentialsProvidersTest, OverseerCollectionConfigSetProcessorTest, OverseerRolesTest, PeerSyncReplicationTest, TestCloudDeleteByQuery, TestCollectionAPI, TestConfigSetsAPIExclusivity, TestConfigSetsAPIZkFailure, TestDeleteCollectionOnDownNodes, TestDistribDocBasedVersion, TestLeaderElectionZkExpiry, TestMiniSolrCloudClusterSSL, TestRequestStatusCollectionAPI, TestShortCircuitedRequests, TestStressLiveNodes, VMParamsZkACLAndCredentialsProvidersTest, HdfsRecoveryZkTest, HdfsUnloadDistributedZkTest, StressHdfsTest, TestClusterStateMutator, BlobRepositoryCloudTest, TestDynamicLoading]
[junit4] Completed [545/672 (1!)] on J1 in 50.85s, 1 test, 1 failure <<< FAILURES!
[...truncated 62902 lines...]