You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2016/11/17 11:28:56 UTC
[JENKINS] Lucene-Solr-Tests-6.x - Build # 539 - Unstable
Build: https://builds.apache.org/job/Lucene-Solr-Tests-6.x/539/
1 tests failed.
FAILED: org.apache.solr.cloud.TestSolrCloudWithDelegationTokens.testDelegationTokenRenew
Error Message:
expected:<200> but was:<403>
Stack Trace:
java.lang.AssertionError: expected:<200> but was:<403>
at __randomizedtesting.SeedInfo.seed([C01105C03CCB275C:F78AF1DE0407FAF8]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.cloud.TestSolrCloudWithDelegationTokens.renewDelegationToken(TestSolrCloudWithDelegationTokens.java:134)
at org.apache.solr.cloud.TestSolrCloudWithDelegationTokens.verifyDelegationTokenRenew(TestSolrCloudWithDelegationTokens.java:319)
at org.apache.solr.cloud.TestSolrCloudWithDelegationTokens.testDelegationTokenRenew(TestSolrCloudWithDelegationTokens.java:336)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java: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 12271 lines...]
[junit4] Suite: org.apache.solr.cloud.TestSolrCloudWithDelegationTokens
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestSolrCloudWithDelegationTokens_C01105C03CCB275C-001/init-core-data-001
[junit4] 2> 1733374 INFO (SUITE-TestSolrCloudWithDelegationTokens-seed#[C01105C03CCB275C]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None)
[junit4] 2> 1733383 INFO (SUITE-TestSolrCloudWithDelegationTokens-seed#[C01105C03CCB275C]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestSolrCloudWithDelegationTokens_C01105C03CCB275C-001/tempDir-001
[junit4] 2> 1733384 INFO (SUITE-TestSolrCloudWithDelegationTokens-seed#[C01105C03CCB275C]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1733384 INFO (Thread-2603) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1733384 INFO (Thread-2603) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1733484 INFO (SUITE-TestSolrCloudWithDelegationTokens-seed#[C01105C03CCB275C]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:60279
[junit4] 2> 1733494 INFO (jetty-launcher-1999-thread-2) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1733496 INFO (jetty-launcher-1999-thread-1) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1733500 INFO (jetty-launcher-1999-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7a398aad{/solr,null,AVAILABLE}
[junit4] 2> 1733500 INFO (jetty-launcher-1999-thread-1) [ ] o.e.j.s.ServerConnector Started ServerConnector@52bd6ba{HTTP/1.1,[http/1.1]}{127.0.0.1:37890}
[junit4] 2> 1733501 INFO (jetty-launcher-1999-thread-1) [ ] o.e.j.s.Server Started @1737470ms
[junit4] 2> 1733501 INFO (jetty-launcher-1999-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=37890}
[junit4] 2> 1733501 ERROR (jetty-launcher-1999-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1733501 INFO (jetty-launcher-1999-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 1733501 INFO (jetty-launcher-1999-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1733501 INFO (jetty-launcher-1999-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1733501 INFO (jetty-launcher-1999-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-17T10:52:59.557Z
[junit4] 2> 1733503 INFO (jetty-launcher-1999-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@39ce38bc{/solr,null,AVAILABLE}
[junit4] 2> 1733503 INFO (jetty-launcher-1999-thread-2) [ ] o.e.j.s.ServerConnector Started ServerConnector@6a06662e{HTTP/1.1,[http/1.1]}{127.0.0.1:54217}
[junit4] 2> 1733503 INFO (jetty-launcher-1999-thread-2) [ ] o.e.j.s.Server Started @1737472ms
[junit4] 2> 1733503 INFO (jetty-launcher-1999-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=54217}
[junit4] 2> 1733503 ERROR (jetty-launcher-1999-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1733503 INFO (jetty-launcher-1999-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 1733503 INFO (jetty-launcher-1999-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1733503 INFO (jetty-launcher-1999-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1733503 INFO (jetty-launcher-1999-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-17T10:52:59.559Z
[junit4] 2> 1733514 INFO (jetty-launcher-1999-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1733514 INFO (jetty-launcher-1999-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1733527 INFO (jetty-launcher-1999-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1733527 INFO (jetty-launcher-1999-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60279/solr
[junit4] 2> 1733542 INFO (jetty-launcher-1999-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1733543 INFO (jetty-launcher-1999-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60279/solr
[junit4] 2> 1733584 INFO (jetty-launcher-1999-thread-2) [n:127.0.0.1:54217_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:54217_solr
[junit4] 2> 1733586 INFO (jetty-launcher-1999-thread-2) [n:127.0.0.1:54217_solr ] o.a.s.c.Overseer Overseer (id=96952646332710916-127.0.0.1:54217_solr-n_0000000000) starting
[junit4] 2> 1733587 INFO (jetty-launcher-1999-thread-1) [n:127.0.0.1:37890_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37890_solr
[junit4] 2> 1733592 INFO (zkCallback-2010-thread-1-processing-n:127.0.0.1:37890_solr) [n:127.0.0.1:37890_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1733598 INFO (OverseerStateUpdate-96952646332710916-127.0.0.1:54217_solr-n_0000000000) [n:127.0.0.1:54217_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1733616 INFO (jetty-launcher-1999-thread-2) [n:127.0.0.1:54217_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54217_solr
[junit4] 2> 1733619 INFO (zkCallback-2010-thread-1-processing-n:127.0.0.1:37890_solr) [n:127.0.0.1:37890_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1733620 INFO (zkCallback-2006-thread-1-processing-n:127.0.0.1:54217_solr) [n:127.0.0.1:54217_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1733691 INFO (jetty-launcher-1999-thread-2) [n:127.0.0.1:54217_solr ] o.a.s.c.CoreContainer Authentication plugin class obtained from system property 'authenticationPlugin': org.apache.solr.security.KerberosPlugin
[junit4] 2> 1733706 INFO (jetty-launcher-1999-thread-1) [n:127.0.0.1:37890_solr ] o.a.s.c.CoreContainer Authentication plugin class obtained from system property 'authenticationPlugin': org.apache.solr.security.KerberosPlugin
[junit4] 2> 1733718 INFO (jetty-launcher-1999-thread-2) [n:127.0.0.1:54217_solr ] o.a.s.s.KerberosPlugin Params: {token.valid=30, delegation-token.token-kind=solr-dt, cookie.domain=127.0.0.1, cookie.path=/, zk-dt-secret-manager.znodeWorkingPath=solr/security/zkdtsm, token.validity=36000, signer.secret.provider.zookeeper.path=/token, type=org.apache.solr.security.HttpParamDelegationTokenAuthenticationHandler, zk-dt-secret-manager.enable=true, kerberos.name.rules=DEFAULT, signer.secret.provider=zookeeper}
[junit4] 2> 1733721 INFO (jetty-launcher-1999-thread-1) [n:127.0.0.1:37890_solr ] o.a.s.s.KerberosPlugin Params: {token.valid=30, delegation-token.token-kind=solr-dt, cookie.domain=127.0.0.1, cookie.path=/, zk-dt-secret-manager.znodeWorkingPath=solr/security/zkdtsm, token.validity=36000, signer.secret.provider.zookeeper.path=/token, type=org.apache.solr.security.HttpParamDelegationTokenAuthenticationHandler, zk-dt-secret-manager.enable=true, kerberos.name.rules=DEFAULT, signer.secret.provider=zookeeper}
[junit4] 2> 1733858 INFO (jetty-launcher-1999-thread-1) [n:127.0.0.1:37890_solr ] o.a.c.f.i.CuratorFrameworkImpl Starting
[junit4] 2> 1733858 INFO (jetty-launcher-1999-thread-2) [n:127.0.0.1:54217_solr ] o.a.c.f.i.CuratorFrameworkImpl Starting
[junit4] 2> 1733895 INFO (jetty-launcher-1999-thread-2-EventThread) [n:127.0.0.1:54217_solr ] o.a.c.f.s.ConnectionStateManager State change: CONNECTED
[junit4] 2> 1733897 INFO (jetty-launcher-1999-thread-1-EventThread) [n:127.0.0.1:37890_solr ] o.a.c.f.s.ConnectionStateManager State change: CONNECTED
[junit4] 2> 1734195 INFO (jetty-launcher-1999-thread-1) [n:127.0.0.1:37890_solr ] o.a.s.h.c.HttpShardHandlerFactory Reconfiguring the default client with: org.apache.solr.client.solrj.impl.Krb5HttpClientConfigurer@7a44430d
[junit4] 2> 1734195 INFO (jetty-launcher-1999-thread-1) [n:127.0.0.1:37890_solr ] o.a.s.u.UpdateShardHandler Reconfiguring the default client with: org.apache.solr.client.solrj.impl.Krb5HttpClientConfigurer@7a44430d
[junit4] 2> 1734196 INFO (jetty-launcher-1999-thread-1) [n:127.0.0.1:37890_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestSolrCloudWithDelegationTokens_C01105C03CCB275C-001/tempDir-001/node1/.
[junit4] 2> 1734196 INFO (jetty-launcher-1999-thread-2) [n:127.0.0.1:54217_solr ] o.a.s.h.c.HttpShardHandlerFactory Reconfiguring the default client with: org.apache.solr.client.solrj.impl.Krb5HttpClientConfigurer@1c9bcf76
[junit4] 2> 1734196 INFO (jetty-launcher-1999-thread-2) [n:127.0.0.1:54217_solr ] o.a.s.u.UpdateShardHandler Reconfiguring the default client with: org.apache.solr.client.solrj.impl.Krb5HttpClientConfigurer@1c9bcf76
[junit4] 2> 1734197 INFO (jetty-launcher-1999-thread-2) [n:127.0.0.1:54217_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestSolrCloudWithDelegationTokens_C01105C03CCB275C-001/tempDir-001/node2/.
[junit4] 2> 1734244 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenew-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDelegationTokenRenew
[junit4] 2> 1734803 WARN (qtp1889884416-11332) [ ] o.a.h.s.a.s.AuthenticationFilter Authentication exception: org.apache.hadoop.security.AccessControlException: bar is trying to renew a token with wrong password
[junit4] 2> 1734804 WARN (qtp1889884416-11332) [ ] o.a.s.s.KerberosPlugin Could not find org.apache.solr.security.kerberosplugin.requestcontinues
[junit4] 2> 1734812 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenew-seed#[C01105C03CCB275C]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires= , 01- -1970 00:00:00 GMT; HttpOnly". Invalid 'expires' attribute: , 01- -1970 00:00:00 GMT
[junit4] 2> 1734813 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenew-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDelegationTokenRenew
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestSolrCloudWithDelegationTokens -Dtests.method=testDelegationTokenRenew -Dtests.seed=C01105C03CCB275C -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=sr -Dtests.timezone=Europe/Simferopol -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 0.60s J0 | TestSolrCloudWithDelegationTokens.testDelegationTokenRenew <<<
[junit4] > Throwable #1: java.lang.AssertionError: expected:<200> but was:<403>
[junit4] > at __randomizedtesting.SeedInfo.seed([C01105C03CCB275C:F78AF1DE0407FAF8]:0)
[junit4] > at org.apache.solr.cloud.TestSolrCloudWithDelegationTokens.renewDelegationToken(TestSolrCloudWithDelegationTokens.java:134)
[junit4] > at org.apache.solr.cloud.TestSolrCloudWithDelegationTokens.verifyDelegationTokenRenew(TestSolrCloudWithDelegationTokens.java:319)
[junit4] > at org.apache.solr.cloud.TestSolrCloudWithDelegationTokens.testDelegationTokenRenew(TestSolrCloudWithDelegationTokens.java:336)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1734839 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenSolrClient-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDelegationTokenSolrClient
[junit4] 2> 1734870 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenSolrClient-seed#[C01105C03CCB275C]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires= , 01- -1970 00:00:00 GMT; HttpOnly". Invalid 'expires' attribute: , 01- -1970 00:00:00 GMT
[junit4] 2> 1734885 INFO (qtp1889884416-11327) [n:127.0.0.1:54217_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&delegation=GgADYmFyA2JhcgCKAVhx6xJiigFYlfeWYgIEFK33gB8k-PsBDgRAkqiEvnEpufMHB3NvbHItZHQA&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1734885 INFO (qtp1889884416-11327) [n:127.0.0.1:54217_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&delegation=GgADYmFyA2JhcgCKAVhx6xJiigFYlfeWYgIEFK33gB8k-PsBDgRAkqiEvnEpufMHB3NvbHItZHQA&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1734886 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenSolrClient-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDelegationTokenSolrClient
[junit4] 2> 1734924 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancelFail-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDelegationTokenCancelFail
[junit4] 2> 1734954 ERROR (qtp434019113-11335) [ ] o.a.h.s.t.d.ZKDelegationTokenSecretManager No node in path [/ZKDTSMTokensRoot/DT_3]
[junit4] 2> 1734962 ERROR (qtp1889884416-11342) [ ] o.a.h.s.t.d.ZKDelegationTokenSecretManager No node in path [/ZKDTSMTokensRoot/DT_3]
[junit4] 2> 1734983 ERROR (qtp434019113-11336) [ ] o.a.h.s.t.d.ZKDelegationTokenSecretManager No node in path [/ZKDTSMTokensRoot/DT_4]
[junit4] 2> 1734985 ERROR (qtp1889884416-11327) [n:127.0.0.1:54217_solr ] o.a.h.s.t.d.ZKDelegationTokenSecretManager No node in path [/ZKDTSMTokensRoot/DT_4]
[junit4] 2> 1734986 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancelFail-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDelegationTokenCancelFail
[junit4] 2> 1735029 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDelegationTokenCancel
[junit4] 2> 1735054 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[C01105C03CCB275C]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1735062 ERROR (qtp434019113-11330) [ ] o.a.h.s.t.d.ZKDelegationTokenSecretManager No node in path [/ZKDTSMTokensRoot/DT_5]
[junit4] 2> 1735082 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[C01105C03CCB275C]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires= , 01- -1970 00:00:00 GMT; HttpOnly". Invalid 'expires' attribute: , 01- -1970 00:00:00 GMT
[junit4] 2> 1735088 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[C01105C03CCB275C]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1735094 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[C01105C03CCB275C]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires= , 01- -1970 00:00:00 GMT; HttpOnly". Invalid 'expires' attribute: , 01- -1970 00:00:00 GMT
[junit4] 2> 1735140 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[C01105C03CCB275C]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1735143 ERROR (qtp434019113-11328) [ ] o.a.h.s.t.d.ZKDelegationTokenSecretManager No node in path [/ZKDTSMTokensRoot/DT_6]
[junit4] 2> 1735152 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[C01105C03CCB275C]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1735156 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[C01105C03CCB275C]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires= , 01- -1970 00:00:00 GMT; HttpOnly". Invalid 'expires' attribute: , 01- -1970 00:00:00 GMT
[junit4] 2> 1735160 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[C01105C03CCB275C]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires= , 01- -1970 00:00:00 GMT; HttpOnly". Invalid 'expires' attribute: , 01- -1970 00:00:00 GMT
[junit4] 2> 1735160 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenCancel-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDelegationTokenCancel
[junit4] 2> 1735193 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationOtherOp-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDelegationOtherOp
[junit4] 2> 1735198 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationOtherOp-seed#[C01105C03CCB275C]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1735204 INFO (qtp434019113-11328) [n:127.0.0.1:37890_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params op=someSolrOperation&action=LIST&user=bar&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1735204 INFO (qtp434019113-11328) [n:127.0.0.1:37890_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={op=someSolrOperation&action=LIST&user=bar&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1735205 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationOtherOp-seed#[C01105C03CCB275C]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth="u=bar&p=bar&t=test&e=1479415981259&s=w3HljFCWl/pTb6k9tVKHgCU7T9w="; Path=/; Domain=127.0.0.1; Expires= , 17- -2016 20:53:01 GMT; HttpOnly". Invalid 'expires' attribute: , 17- -2016 20:53:01 GMT
[junit4] 2> 1735207 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationOtherOp-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDelegationOtherOp
[junit4] 2> 1735245 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDelegationTokenVerify
[junit4] 2> 1735274 INFO (qtp1889884416-11326) [n:127.0.0.1:54217_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&delegation=GgADYmFyA2JhcgCKAVhx6xP9igFYlfeX_QcEFPU34rb99GYYN64aj1Xk25fQHyBcB3NvbHItZHQA&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1735274 INFO (qtp1889884416-11326) [n:127.0.0.1:54217_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&delegation=GgADYmFyA2JhcgCKAVhx6xP9igFYlfeX_QcEFPU34rb99GYYN64aj1Xk25fQHyBcB3NvbHItZHQA&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1735283 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[C01105C03CCB275C]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1735289 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[C01105C03CCB275C]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires= , 01- -1970 00:00:00 GMT; HttpOnly". Invalid 'expires' attribute: , 01- -1970 00:00:00 GMT
[junit4] 2> 1735294 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[C01105C03CCB275C]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1735296 INFO (qtp434019113-11338) [n:127.0.0.1:37890_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&delegation=GgADYmFyA2JhcgCKAVhx6xP9igFYlfeX_QcEFPU34rb99GYYN64aj1Xk25fQHyBcB3NvbHItZHQA&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1735296 INFO (qtp434019113-11338) [n:127.0.0.1:37890_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&delegation=GgADYmFyA2JhcgCKAVhx6xP9igFYlfeX_QcEFPU34rb99GYYN64aj1Xk25fQHyBcB3NvbHItZHQA&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1735320 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[C01105C03CCB275C]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1735324 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[C01105C03CCB275C]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires= , 01- -1970 00:00:00 GMT; HttpOnly". Invalid 'expires' attribute: , 01- -1970 00:00:00 GMT
[junit4] 2> 1735331 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenVerify-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDelegationTokenVerify
[junit4] 2> 1735348 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenewFail-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDelegationTokenRenewFail
[junit4] 2> 1735361 WARN (qtp1889884416-11332) [ ] o.a.h.s.a.s.AuthenticationFilter Authentication exception: org.apache.hadoop.security.AccessControlException: foo tries to renew a token with renewer bar
[junit4] 2> 1735362 WARN (qtp1889884416-11332) [ ] o.a.s.s.KerberosPlugin Could not find org.apache.solr.security.kerberosplugin.requestcontinues
[junit4] 2> 1735362 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenewFail-seed#[C01105C03CCB275C]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires= , 01- -1970 00:00:00 GMT; HttpOnly". Invalid 'expires' attribute: , 01- -1970 00:00:00 GMT
[junit4] 2> 1735364 WARN (qtp434019113-11330) [ ] o.a.h.s.a.s.AuthenticationFilter Authentication exception: org.apache.hadoop.security.AccessControlException: foo tries to renew a token with renewer bar
[junit4] 2> 1735364 WARN (qtp434019113-11330) [ ] o.a.s.s.KerberosPlugin Could not find org.apache.solr.security.kerberosplugin.requestcontinues
[junit4] 2> 1735365 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenewFail-seed#[C01105C03CCB275C]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires= , 01- -1970 00:00:00 GMT; HttpOnly". Invalid 'expires' attribute: , 01- -1970 00:00:00 GMT
[junit4] 2> 1735385 WARN (qtp1889884416-11344) [ ] o.a.h.s.a.s.AuthenticationFilter Authentication exception: org.apache.hadoop.security.AccessControlException: notRenewUser tries to renew a token with renewer renewUser
[junit4] 2> 1735385 WARN (qtp1889884416-11344) [ ] o.a.s.s.KerberosPlugin Could not find org.apache.solr.security.kerberosplugin.requestcontinues
[junit4] 2> 1735385 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenewFail-seed#[C01105C03CCB275C]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires= , 01- -1970 00:00:00 GMT; HttpOnly". Invalid 'expires' attribute: , 01- -1970 00:00:00 GMT
[junit4] 2> 1735387 WARN (qtp434019113-11330) [ ] o.a.h.s.a.s.AuthenticationFilter Authentication exception: org.apache.hadoop.security.AccessControlException: notRenewUser tries to renew a token with renewer renewUser
[junit4] 2> 1735388 WARN (qtp434019113-11330) [ ] o.a.s.s.KerberosPlugin Could not find org.apache.solr.security.kerberosplugin.requestcontinues
[junit4] 2> 1735388 WARN (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenewFail-seed#[C01105C03CCB275C]) [ ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=; Path=/; Domain=127.0.0.1; Expires= , 01- -1970 00:00:00 GMT; HttpOnly". Invalid 'expires' attribute: , 01- -1970 00:00:00 GMT
[junit4] 2> 1735388 INFO (TEST-TestSolrCloudWithDelegationTokens.testDelegationTokenRenewFail-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDelegationTokenRenewFail
[junit4] 2> 1735460 INFO (TEST-TestSolrCloudWithDelegationTokens.testZNodePaths-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testZNodePaths
[junit4] 2> 1735495 INFO (TEST-TestSolrCloudWithDelegationTokens.testZNodePaths-seed#[C01105C03CCB275C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testZNodePaths
[junit4] 2> 1735496 INFO (jetty-launcher-1999-thread-1) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@6a06662e{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1735496 INFO (jetty-launcher-1999-thread-2) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@52bd6ba{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1735497 INFO (jetty-launcher-1999-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=877685342
[junit4] 2> 1735497 INFO (jetty-launcher-1999-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1996455662
[junit4] 2> 1735510 INFO (jetty-launcher-1999-thread-1) [ ] o.a.s.c.Overseer Overseer (id=96952646332710916-127.0.0.1:54217_solr-n_0000000000) closing
[junit4] 2> 1735510 INFO (OverseerStateUpdate-96952646332710916-127.0.0.1:54217_solr-n_0000000000) [n:127.0.0.1:54217_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:54217_solr
[junit4] 2> 1735512 WARN (zkCallback-2010-thread-1-processing-n:127.0.0.1:37890_solr) [n:127.0.0.1:37890_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1735512 ERROR (Thread[Thread-2622,5,TGRP-TestSolrCloudWithDelegationTokens]) [n:127.0.0.1:37890_solr ] o.a.h.s.t.d.AbstractDelegationTokenSecretManager ExpiredTokenRemover received java.lang.InterruptedException: sleep interrupted
[junit4] 2> 1735513 ERROR (Thread[Thread-2621,5,TGRP-TestSolrCloudWithDelegationTokens]) [n:127.0.0.1:54217_solr ] o.a.h.s.t.d.AbstractDelegationTokenSecretManager ExpiredTokenRemover received java.lang.InterruptedException: sleep interrupted
[junit4] 2> 1735527 INFO (jetty-launcher-1999-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@39ce38bc{/solr,null,UNAVAILABLE}
[junit4] 2> 1735533 INFO (jetty-launcher-1999-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7a398aad{/solr,null,UNAVAILABLE}
[junit4] 2> 1735535 INFO (SUITE-TestSolrCloudWithDelegationTokens-seed#[C01105C03CCB275C]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:60279 60279
[junit4] 2> 1735617 INFO (Thread-2603) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:60279 60279
[junit4] 2> 1735621 WARN (Thread-2603) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 10 /solr/aliases.json
[junit4] 2> 10 /solr/clusterprops.json
[junit4] 2> 2 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 10 /solr/clusterstate.json
[junit4] 2> 4 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMKeyIdRoot
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_7
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_6
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_9
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_8
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoot/DK_1
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_1
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_3
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoot/DK_2
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_2
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_5
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoot/DK_4
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_4
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMSeqNumRoot
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot/DT_10
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 10 /solr/live_nodes
[junit4] 2> 10 /solr/collections
[junit4] 2> 3 /solr/overseer/queue
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoot
[junit4] 2> 2 /solr/overseer/queue-work
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot
[junit4] 2>
[junit4] 2> 1735622 INFO (SUITE-TestSolrCloudWithDelegationTokens-seed#[C01105C03CCB275C]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestSolrCloudWithDelegationTokens_C01105C03CCB275C-001
[junit4] 2> Nov 17, 2016 10:53:01 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {}, docValues:{}, maxPointsInLeafNode=495, maxMBSortInHeap=6.702278801668251, sim=RandomSimilarity(queryNorm=true,coord=yes): {}, locale=sr, timezone=Europe/Simferopol
[junit4] 2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8.0_102 (64-bit)/cpus=4,threads=1,free=70320800,total=523239424
[junit4] 2> NOTE: All tests run in this JVM: [TriLevelCompositeIdRoutingTest, TestConfigSetImmutable, TestFastWriter, CollectionTooManyReplicasTest, BlockJoinFacetSimpleTest, SortSpecParsingTest, ResourceLoaderTest, TestShortCircuitedRequests, TestCodecSupport, TestUseDocValuesAsStored2, TestPerFieldSimilarity, TestGeoJSONResponseWriter, AnalysisAfterCoreReloadTest, TestCorePropertiesReload, DateRangeFieldTest, UUIDUpdateProcessorFallbackTest, DistributedFacetPivotWhiteBoxTest, HdfsBasicDistributedZkTest, TestRealTimeGet, TestMinMaxOnMultiValuedField, RequiredFieldsTest, TestPHPSerializedResponseWriter, DirectoryFactoryTest, TestLegacyFieldCache, TestFieldCacheReopen, NumericFieldsTest, BasicZkTest, TestRandomRequestDistribution, TestCloudPivotFacet, TestPivotHelperCode, StandardRequestHandlerTest, BadCopyFieldTest, SignatureUpdateProcessorFactoryTest, RecoveryAfterSoftCommitTest, TestDocumentBuilder, TestSolrCoreProperties, BJQParserTest, ScriptEngineTest, TestCrossCoreJoin, ZkNodePropsTest, AsyncCallRequestStatusResponseTest, HighlighterConfigTest, DistribDocExpirationUpdateProcessorTest, UniqFieldsUpdateProcessorFactoryTest, TestRestManager, TestLeaderElectionZkExpiry, TestChildDocTransformer, TestRawResponseWriter, CdcrVersionReplicationTest, DistributedExpandComponentTest, TestSearcherReuse, TestSerializedLuceneMatchVersion, TestHashQParserPlugin, TestFieldSortValues, TestRangeQuery, TestScoreJoinQPScore, OutputWriterTest, DisMaxRequestHandlerTest, UUIDFieldTest, TestRTimerTree, TestJoin, TestStressRecovery, TestStressLucene, TestFieldTypeCollectionResource, TestIBSimilarityFactory, TestFunctionQuery, SyncSliceTest, TestNRTOpen, TestAnalyzeInfixSuggestions, CursorPagingTest, UtilsToolTest, DistributedSpellCheckComponentTest, TestUniqueKeyFieldResource, MBeansHandlerTest, TestJmxIntegration, DistributedFacetPivotLongTailTest, TestCopyFieldCollectionResource, TemplateUpdateProcessorTest, DefaultValueUpdateProcessorTest, TestManagedSchemaThreadSafety, QueryElevationComponentTest, TestDocBasedVersionConstraints, ChaosMonkeyNothingIsSafeTest, LeaderInitiatedRecoveryOnCommitTest, HighlighterMaxOffsetTest, TestQuerySenderNoQuery, TestRandomFaceting, LeaderElectionIntegrationTest, FileBasedSpellCheckerTest, SynonymTokenizerTest, TestMissingGroups, TestPKIAuthenticationPlugin, TestFaceting, TestRemoteStreaming, TestAtomicUpdateErrorCases, ReplicationFactorTest, CurrencyFieldOpenExchangeTest, TestReRankQParserPlugin, LeaderElectionContextKeyTest, ExternalFileFieldSortTest, BasicDistributedZkTest, HLLSerializationTest, RuleEngineTest, BitVectorTest, CloudExitableDirectoryReaderTest, QueryEqualityTest, TestSolrDeletionPolicy2, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, OverseerTest, TestReplicationHandler, ZkCLITest, TestDistributedSearch, TestSolr4Spatial, SpellCheckComponentTest, TestFiltering, TestIndexSearcher, HighlighterTest, ShowFileRequestHandlerTest, DistributedQueryElevationComponentTest, SimplePostToolTest, SuggesterFSTTest, SolrRequestParserTest, DocValuesTest, XmlUpdateRequestHandlerTest, TestValueSourceCache, TestIndexingPerformance, FastVectorHighlighterTest, LoggingHandlerTest, ReturnFieldsTest, QueryParsingTest, TestPartialUpdateDeduplication, TestComponentsName, SOLR749Test, BadComponentTest, TestDocSet, TestPostingsSolrHighlighter, TestPhraseSuggestions, TestSweetSpotSimilarityFactory, TestBM25SimilarityFactory, URLClassifyProcessorTest, PluginInfoTest, PreAnalyzedFieldTest, ClusterStateTest, FileUtilsTest, TestSimpleTrackingShardHandler, CdcrReplicationDistributedZkTest, CollectionReloadTest, CollectionsAPIAsyncDistributedZkTest, ConcurrentDeleteAndCreateCollectionTest, ConnectionManagerTest, CustomCollectionTest, ForceLeaderTest, RestartWhileUpdatingTest, SSLMigrationTest, SharedFSAutoReplicaFailoverTest, SharedFSAutoReplicaFailoverUtilsTest, SolrCLIZkUtilsTest, SolrXmlInZkTest, TestAuthenticationFramework, TestClusterProperties, TestConfigSetsAPIExclusivity, TestDeleteCollectionOnDownNodes, TestExclusionRuleCollectionAccess, TestLeaderInitiatedRecoveryThread, TestLockTree, TestMiniSolrCloudClusterSSL, TestSSLRandomization, TestSolrCloudWithDelegationTokens]
[junit4] Completed [506/653 (1!)] on J0 in 2.77s, 8 tests, 1 failure <<< FAILURES!
[...truncated 61209 lines...]
[JENKINS] Lucene-Solr-Tests-6.x - Build # 540 - Still Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-6.x/540/
1 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.search.join.BlockJoinFacetDistribTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.search.join.BlockJoinFacetDistribTest: 1) Thread[id=16926, name=OverseerHdfsCoreFailoverThread-96954144056541199-127.0.0.1:48006_solr-n_0000000004, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.] at java.lang.Thread.sleep(Native Method) at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:137) at java.lang.Thread.run(Thread.java:745)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.search.join.BlockJoinFacetDistribTest:
1) Thread[id=16926, name=OverseerHdfsCoreFailoverThread-96954144056541199-127.0.0.1:48006_solr-n_0000000004, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
at java.lang.Thread.sleep(Native Method)
at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:137)
at java.lang.Thread.run(Thread.java:745)
at __randomizedtesting.SeedInfo.seed([FF863684FC708662]:0)
Build Log:
[...truncated 12666 lines...]
[junit4] Suite: org.apache.solr.search.join.BlockJoinFacetDistribTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/init-core-data-001
[junit4] 2> 2290858 INFO (SUITE-BlockJoinFacetDistribTest-seed#[FF863684FC708662]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 2290859 INFO (SUITE-BlockJoinFacetDistribTest-seed#[FF863684FC708662]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 6 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001
[junit4] 2> 2290859 INFO (SUITE-BlockJoinFacetDistribTest-seed#[FF863684FC708662]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2290861 INFO (Thread-5399) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2290862 INFO (Thread-5399) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2290961 INFO (SUITE-BlockJoinFacetDistribTest-seed#[FF863684FC708662]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:33148
[junit4] 2> 2291057 INFO (jetty-launcher-2487-thread-2) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 2291065 INFO (jetty-launcher-2487-thread-3) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 2291070 INFO (jetty-launcher-2487-thread-1) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 2291072 INFO (jetty-launcher-2487-thread-4) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 2291074 INFO (jetty-launcher-2487-thread-5) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 2291097 INFO (jetty-launcher-2487-thread-6) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 2291171 INFO (jetty-launcher-2487-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@12ed7a9f{/solr,null,AVAILABLE}
[junit4] 2> 2291173 INFO (jetty-launcher-2487-thread-2) [ ] o.e.j.s.ServerConnector Started ServerConnector@a6f10b5{SSL,[ssl, http/1.1]}{127.0.0.1:50764}
[junit4] 2> 2291173 INFO (jetty-launcher-2487-thread-2) [ ] o.e.j.s.Server Started @2295263ms
[junit4] 2> 2291173 INFO (jetty-launcher-2487-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=50764}
[junit4] 2> 2291173 ERROR (jetty-launcher-2487-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2291173 INFO (jetty-launcher-2487-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2291173 INFO (jetty-launcher-2487-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2291174 INFO (jetty-launcher-2487-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2291174 INFO (jetty-launcher-2487-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-17T17:13:53.192Z
[junit4] 2> 2291287 INFO (jetty-launcher-2487-thread-5) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2bb5afd6{/solr,null,AVAILABLE}
[junit4] 2> 2291288 INFO (jetty-launcher-2487-thread-5) [ ] o.e.j.s.ServerConnector Started ServerConnector@59863acb{SSL,[ssl, http/1.1]}{127.0.0.1:43659}
[junit4] 2> 2291289 INFO (jetty-launcher-2487-thread-5) [ ] o.e.j.s.Server Started @2295379ms
[junit4] 2> 2291289 INFO (jetty-launcher-2487-thread-5) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43659}
[junit4] 2> 2291289 ERROR (jetty-launcher-2487-thread-5) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2291289 INFO (jetty-launcher-2487-thread-5) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2291289 INFO (jetty-launcher-2487-thread-5) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2291289 INFO (jetty-launcher-2487-thread-5) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2291289 INFO (jetty-launcher-2487-thread-5) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-17T17:13:53.307Z
[junit4] 2> 2291367 INFO (jetty-launcher-2487-thread-5) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2291571 INFO (jetty-launcher-2487-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@44888fc4{/solr,null,AVAILABLE}
[junit4] 2> 2291572 INFO (jetty-launcher-2487-thread-1) [ ] o.e.j.s.ServerConnector Started ServerConnector@5c4d5dc1{SSL,[ssl, http/1.1]}{127.0.0.1:48006}
[junit4] 2> 2291573 INFO (jetty-launcher-2487-thread-1) [ ] o.e.j.s.Server Started @2295663ms
[junit4] 2> 2291573 INFO (jetty-launcher-2487-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=48006}
[junit4] 2> 2291573 ERROR (jetty-launcher-2487-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2291573 INFO (jetty-launcher-2487-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2291573 INFO (jetty-launcher-2487-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2291573 INFO (jetty-launcher-2487-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2291573 INFO (jetty-launcher-2487-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-17T17:13:53.591Z
[junit4] 2> 2291584 INFO (jetty-launcher-2487-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2291645 INFO (jetty-launcher-2487-thread-6) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5e8f8755{/solr,null,AVAILABLE}
[junit4] 2> 2291647 INFO (jetty-launcher-2487-thread-6) [ ] o.e.j.s.ServerConnector Started ServerConnector@2f458a94{SSL,[ssl, http/1.1]}{127.0.0.1:38313}
[junit4] 2> 2291647 INFO (jetty-launcher-2487-thread-6) [ ] o.e.j.s.Server Started @2295737ms
[junit4] 2> 2291647 INFO (jetty-launcher-2487-thread-6) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=38313}
[junit4] 2> 2291647 ERROR (jetty-launcher-2487-thread-6) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2291647 INFO (jetty-launcher-2487-thread-6) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2291648 INFO (jetty-launcher-2487-thread-6) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2291648 INFO (jetty-launcher-2487-thread-6) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2291648 INFO (jetty-launcher-2487-thread-6) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-17T17:13:53.666Z
[junit4] 2> 2291747 INFO (jetty-launcher-2487-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2291767 INFO (jetty-launcher-2487-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2291771 INFO (jetty-launcher-2487-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33148/solr
[junit4] 2> 2291825 INFO (jetty-launcher-2487-thread-5) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2291846 INFO (jetty-launcher-2487-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@8b39d1e{/solr,null,AVAILABLE}
[junit4] 2> 2291847 INFO (jetty-launcher-2487-thread-3) [ ] o.e.j.s.ServerConnector Started ServerConnector@484688ae{SSL,[ssl, http/1.1]}{127.0.0.1:50797}
[junit4] 2> 2291848 INFO (jetty-launcher-2487-thread-3) [ ] o.e.j.s.Server Started @2295938ms
[junit4] 2> 2291848 INFO (jetty-launcher-2487-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=50797}
[junit4] 2> 2291848 ERROR (jetty-launcher-2487-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2291848 INFO (jetty-launcher-2487-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2291848 INFO (jetty-launcher-2487-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2291848 INFO (jetty-launcher-2487-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2291848 INFO (jetty-launcher-2487-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-17T17:13:53.866Z
[junit4] 2> 2291942 INFO (jetty-launcher-2487-thread-5) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33148/solr
[junit4] 2> 2291983 INFO (jetty-launcher-2487-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@74cba4b7{/solr,null,AVAILABLE}
[junit4] 2> 2291984 INFO (jetty-launcher-2487-thread-4) [ ] o.e.j.s.ServerConnector Started ServerConnector@58b1b951{SSL,[ssl, http/1.1]}{127.0.0.1:39448}
[junit4] 2> 2291985 INFO (jetty-launcher-2487-thread-4) [ ] o.e.j.s.Server Started @2296075ms
[junit4] 2> 2291985 INFO (jetty-launcher-2487-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39448}
[junit4] 2> 2291985 ERROR (jetty-launcher-2487-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2291985 INFO (jetty-launcher-2487-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2291985 INFO (jetty-launcher-2487-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2291985 INFO (jetty-launcher-2487-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2291985 INFO (jetty-launcher-2487-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-17T17:13:54.003Z
[junit4] 2> 2292080 INFO (jetty-launcher-2487-thread-6) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2292087 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 0x1587347c3fe0005, 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> 2292095 INFO (jetty-launcher-2487-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2292099 INFO (jetty-launcher-2487-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2292106 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 0x1587347c3fe0007, 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> 2292111 INFO (jetty-launcher-2487-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2292127 INFO (jetty-launcher-2487-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33148/solr
[junit4] 2> 2292153 INFO (jetty-launcher-2487-thread-4) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2292159 INFO (jetty-launcher-2487-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33148/solr
[junit4] 2> 2292219 INFO (jetty-launcher-2487-thread-6) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2292231 INFO (jetty-launcher-2487-thread-6) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33148/solr
[junit4] 2> 2292275 INFO (jetty-launcher-2487-thread-3) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2292338 INFO (jetty-launcher-2487-thread-2) [n:127.0.0.1:50764_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:50764_solr
[junit4] 2> 2292340 INFO (jetty-launcher-2487-thread-2) [n:127.0.0.1:50764_solr ] o.a.s.c.Overseer Overseer (id=96954144056541194-127.0.0.1:50764_solr-n_0000000000) starting
[junit4] 2> 2292363 INFO (jetty-launcher-2487-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33148/solr
[junit4] 2> 2292524 INFO (jetty-launcher-2487-thread-4) [n:127.0.0.1:39448_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39448_solr
[junit4] 2> 2292528 INFO (jetty-launcher-2487-thread-5) [n:127.0.0.1:43659_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43659_solr
[junit4] 2> 2292599 INFO (zkCallback-2508-thread-1-processing-n:127.0.0.1:43659_solr) [n:127.0.0.1:43659_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2292601 INFO (OverseerStateUpdate-96954144056541194-127.0.0.1:50764_solr-n_0000000000) [n:127.0.0.1:50764_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2292601 INFO (jetty-launcher-2487-thread-2) [n:127.0.0.1:50764_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50764_solr
[junit4] 2> 2292603 INFO (zkCallback-2508-thread-1-processing-n:127.0.0.1:43659_solr) [n:127.0.0.1:43659_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2292627 INFO (zkCallback-2516-thread-1-processing-n:127.0.0.1:38313_solr) [n:127.0.0.1:38313_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 2292628 INFO (zkCallback-2514-thread-1-processing-n:127.0.0.1:48006_solr) [n:127.0.0.1:48006_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 2292630 INFO (jetty-launcher-2487-thread-6) [n:127.0.0.1:38313_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38313_solr
[junit4] 2> 2292635 INFO (zkCallback-2515-thread-1-processing-n:127.0.0.1:39448_solr) [n:127.0.0.1:39448_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 2292636 INFO (zkCallback-2503-thread-1-processing-n:127.0.0.1:50764_solr) [n:127.0.0.1:50764_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2292636 INFO (zkCallback-2508-thread-1-processing-n:127.0.0.1:43659_solr) [n:127.0.0.1:43659_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2292637 INFO (zkCallback-2515-thread-1-processing-n:127.0.0.1:39448_solr) [n:127.0.0.1:39448_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2292637 INFO (zkCallback-2516-thread-1-processing-n:127.0.0.1:38313_solr) [n:127.0.0.1:38313_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2292637 INFO (zkCallback-2514-thread-1-processing-n:127.0.0.1:48006_solr) [n:127.0.0.1:48006_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2292640 INFO (jetty-launcher-2487-thread-1) [n:127.0.0.1:48006_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48006_solr
[junit4] 2> 2292641 INFO (zkCallback-2508-thread-1-processing-n:127.0.0.1:43659_solr) [n:127.0.0.1:43659_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2292642 INFO (zkCallback-2515-thread-1-processing-n:127.0.0.1:39448_solr) [n:127.0.0.1:39448_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2292642 INFO (zkCallback-2514-thread-1-processing-n:127.0.0.1:48006_solr) [n:127.0.0.1:48006_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2292643 INFO (zkCallback-2516-thread-1-processing-n:127.0.0.1:38313_solr) [n:127.0.0.1:38313_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2292647 INFO (zkCallback-2503-thread-3-processing-n:127.0.0.1:50764_solr) [n:127.0.0.1:50764_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 2292712 INFO (jetty-launcher-2487-thread-3) [n:127.0.0.1:50797_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5)
[junit4] 2> 2292717 INFO (jetty-launcher-2487-thread-3) [n:127.0.0.1:50797_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50797_solr
[junit4] 2> 2292719 INFO (zkCallback-2515-thread-1-processing-n:127.0.0.1:39448_solr) [n:127.0.0.1:39448_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2292719 INFO (zkCallback-2516-thread-1-processing-n:127.0.0.1:38313_solr) [n:127.0.0.1:38313_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2292719 INFO (zkCallback-2503-thread-1-processing-n:127.0.0.1:50764_solr) [n:127.0.0.1:50764_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2292719 INFO (zkCallback-2508-thread-1-processing-n:127.0.0.1:43659_solr) [n:127.0.0.1:43659_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2292719 INFO (zkCallback-2523-thread-1-processing-n:127.0.0.1:50797_solr) [n:127.0.0.1:50797_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2292720 INFO (zkCallback-2514-thread-1-processing-n:127.0.0.1:48006_solr) [n:127.0.0.1:48006_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2292729 INFO (jetty-launcher-2487-thread-2) [n:127.0.0.1:50764_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node2/.
[junit4] 2> 2292879 INFO (jetty-launcher-2487-thread-5) [n:127.0.0.1:43659_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node5/.
[junit4] 2> 2292898 INFO (jetty-launcher-2487-thread-3) [n:127.0.0.1:50797_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node3/.
[junit4] 2> 2293007 INFO (jetty-launcher-2487-thread-4) [n:127.0.0.1:39448_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node4/.
[junit4] 2> 2293044 INFO (jetty-launcher-2487-thread-1) [n:127.0.0.1:48006_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node1/.
[junit4] 2> 2293147 INFO (jetty-launcher-2487-thread-6) [n:127.0.0.1:38313_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node6/.
[junit4] 2> 2293157 INFO (SUITE-BlockJoinFacetDistribTest-seed#[FF863684FC708662]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (6)
[junit4] 2> 2293782 INFO (qtp1768208227-16735) [n:127.0.0.1:43659_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&property.config=solrconfig-blockjoinfacetcomponent.xml&property.schema=schema-blockjoinfacetcomponent.xml&collection.configName=solrCloudCollectionConfig&name=facetcollection&action=CREATE&numShards=3&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2293809 INFO (OverseerThreadFactory-8131-thread-1-processing-n:127.0.0.1:50764_solr) [n:127.0.0.1:50764_solr ] o.a.s.c.CreateCollectionCmd Create collection facetcollection
[junit4] 2> 2294152 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr ] o.a.s.h.a.CoreAdminOperation core create command property.config=solrconfig-blockjoinfacetcomponent.xml&property.schema=schema-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard1_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard1&wt=javabin&version=2
[junit4] 2> 2294153 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr ] o.a.s.h.a.CoreAdminOperation core create command property.config=solrconfig-blockjoinfacetcomponent.xml&property.schema=schema-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard1_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard1&wt=javabin&version=2
[junit4] 2> 2294154 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr ] o.a.s.h.a.CoreAdminOperation core create command property.config=solrconfig-blockjoinfacetcomponent.xml&property.schema=schema-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard2_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard2&wt=javabin&version=2
[junit4] 2> 2294179 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr ] o.a.s.h.a.CoreAdminOperation core create command property.config=solrconfig-blockjoinfacetcomponent.xml&property.schema=schema-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard3_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard3&wt=javabin&version=2
[junit4] 2> 2294197 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr ] o.a.s.h.a.CoreAdminOperation core create command property.config=solrconfig-blockjoinfacetcomponent.xml&property.schema=schema-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard3_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard3&wt=javabin&version=2
[junit4] 2> 2294204 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr ] o.a.s.h.a.CoreAdminOperation core create command property.config=solrconfig-blockjoinfacetcomponent.xml&property.schema=schema-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard2_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard2&wt=javabin&version=2
[junit4] 2> 2294355 INFO (zkCallback-2516-thread-1-processing-n:127.0.0.1:38313_solr) [n:127.0.0.1:38313_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2294355 INFO (zkCallback-2523-thread-1-processing-n:127.0.0.1:50797_solr) [n:127.0.0.1:50797_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2294355 INFO (zkCallback-2508-thread-1-processing-n:127.0.0.1:43659_solr) [n:127.0.0.1:43659_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2294355 INFO (zkCallback-2514-thread-1-processing-n:127.0.0.1:48006_solr) [n:127.0.0.1:48006_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2294355 INFO (zkCallback-2515-thread-1-processing-n:127.0.0.1:39448_solr) [n:127.0.0.1:39448_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2294356 INFO (zkCallback-2503-thread-3-processing-n:127.0.0.1:50764_solr) [n:127.0.0.1:50764_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2295200 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2295237 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica1] o.a.s.s.IndexSchema [facetcollection_shard2_replica1] Schema name=test
[junit4] 2> 2295248 WARN (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica1] o.a.s.s.IndexSchema [facetcollection_shard2_replica1] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2295249 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2295250 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard2_replica1' using configuration from collection facetcollection
[junit4] 2> 2295251 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.c.SolrCore [[facetcollection_shard2_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node3/facetcollection_shard2_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node3/./facetcollection_shard2_replica1/data/]
[junit4] 2> 2295255 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2295265 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2295269 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2295276 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2295289 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2295298 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica2] o.a.s.s.IndexSchema [facetcollection_shard1_replica2] Schema name=test
[junit4] 2> 2295298 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica1] o.a.s.s.IndexSchema [facetcollection_shard3_replica1] Schema name=test
[junit4] 2> 2295300 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica2] o.a.s.s.IndexSchema [facetcollection_shard3_replica2] Schema name=test
[junit4] 2> 2295308 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica1] o.a.s.s.IndexSchema [facetcollection_shard1_replica1] Schema name=test
[junit4] 2> 2295344 WARN (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica1] o.a.s.s.IndexSchema [facetcollection_shard3_replica1] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2295347 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica2] o.a.s.s.IndexSchema [facetcollection_shard2_replica2] Schema name=test
[junit4] 2> 2295348 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2295356 WARN (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica2] o.a.s.s.IndexSchema [facetcollection_shard3_replica2] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2295357 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica2] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2295358 WARN (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica2] o.a.s.s.IndexSchema [facetcollection_shard1_replica2] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2295358 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica2] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2295358 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica2] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard3_replica2' using configuration from collection facetcollection
[junit4] 2> 2295359 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.c.SolrCore [[facetcollection_shard3_replica2] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node1/facetcollection_shard3_replica2], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node1/./facetcollection_shard3_replica2/data/]
[junit4] 2> 2295359 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard1_replica2' using configuration from collection facetcollection
[junit4] 2> 2295359 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.c.SolrCore [[facetcollection_shard1_replica2] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node2/facetcollection_shard1_replica2], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node2/./facetcollection_shard1_replica2/data/]
[junit4] 2> 2295360 WARN (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica1] o.a.s.s.IndexSchema [facetcollection_shard1_replica1] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2295360 WARN (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica2] o.a.s.s.IndexSchema [facetcollection_shard2_replica2] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2295360 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2295361 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica2] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2295362 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica1] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard3_replica1' using configuration from collection facetcollection
[junit4] 2> 2295362 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard1_replica1' using configuration from collection facetcollection
[junit4] 2> 2295362 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.c.SolrCore [[facetcollection_shard3_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node4/facetcollection_shard3_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node4/./facetcollection_shard3_replica1/data/]
[junit4] 2> 2295362 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.c.SolrCore [[facetcollection_shard1_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node5/facetcollection_shard1_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node5/./facetcollection_shard1_replica1/data/]
[junit4] 2> 2295363 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2295364 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2295365 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2295365 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica2] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard2_replica2' using configuration from collection facetcollection
[junit4] 2> 2295365 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2295365 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.c.SolrCore [[facetcollection_shard2_replica2] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node6/facetcollection_shard2_replica2], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.search.join.BlockJoinFacetDistribTest_FF863684FC708662-001/tempDir-001/node6/./facetcollection_shard2_replica2/data/]
[junit4] 2> 2295367 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@30fe6cdc[facetcollection_shard2_replica1] main]
[junit4] 2> 2295368 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2295369 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2295382 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1551266309629542400
[junit4] 2> 2295383 INFO (searcherExecutor-8144-thread-1-processing-n:127.0.0.1:50797_solr x:facetcollection_shard2_replica1 s:shard2 c:facetcollection r:core_node3) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.c.SolrCore [facetcollection_shard2_replica1] Registered new searcher Searcher@30fe6cdc[facetcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2295393 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms
[junit4] 2> 2295419 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2295419 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2295420 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2295420 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2295421 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@3af0052c[facetcollection_shard2_replica2] main]
[junit4] 2> 2295422 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2295423 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2295427 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2295427 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2295428 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2295428 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2295429 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@56e623df[facetcollection_shard3_replica2] main]
[junit4] 2> 2295430 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2295430 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2295443 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1551266309693505536
[junit4] 2> 2295445 INFO (searcherExecutor-8152-thread-1-processing-n:127.0.0.1:38313_solr x:facetcollection_shard2_replica2 s:shard2 c:facetcollection r:core_node5) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.c.SolrCore [facetcollection_shard2_replica2] Registered new searcher Searcher@3af0052c[facetcollection_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2295449 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2295449 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2295450 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2295450 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2295451 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@3dc00604[facetcollection_shard1_replica2] main]
[junit4] 2> 2295451 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2295451 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2295452 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2295452 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2295452 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@11bf3039[facetcollection_shard1_replica1] main]
[junit4] 2> 2295453 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2295454 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2295454 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1551266309705039872
[junit4] 2> 2295456 INFO (searcherExecutor-8148-thread-1-processing-n:127.0.0.1:43659_solr x:facetcollection_shard1_replica1 s:shard1 c:facetcollection r:core_node2) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.c.SolrCore [facetcollection_shard1_replica1] Registered new searcher Searcher@11bf3039[facetcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2295463 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1551266309714477056
[junit4] 2> 2295463 INFO (searcherExecutor-8145-thread-1-processing-n:127.0.0.1:48006_solr x:facetcollection_shard3_replica2 s:shard3 c:facetcollection r:core_node4) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.c.SolrCore [facetcollection_shard3_replica2] Registered new searcher Searcher@56e623df[facetcollection_shard3_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2295466 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2295467 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2295470 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 2295472 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard3: total=2 found=1 timeoutin=9999ms
[junit4] 2> 2295475 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2295475 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2295476 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2295476 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2295476 INFO (searcherExecutor-8146-thread-1-processing-n:127.0.0.1:50764_solr x:facetcollection_shard1_replica2 s:shard1 c:facetcollection r:core_node1) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.c.SolrCore [facetcollection_shard1_replica2] Registered new searcher Searcher@3dc00604[facetcollection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2295476 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1551266309728108544
[junit4] 2> 2295481 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@13b8b85f[facetcollection_shard3_replica1] main]
[junit4] 2> 2295482 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2295482 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2295482 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1551266309734400000
[junit4] 2> 2295492 INFO (searcherExecutor-8147-thread-1-processing-n:127.0.0.1:39448_solr x:facetcollection_shard3_replica1 s:shard3 c:facetcollection r:core_node6) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.c.SolrCore [facetcollection_shard3_replica1] Registered new searcher Searcher@13b8b85f[facetcollection_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2295574 INFO (zkCallback-2516-thread-1-processing-n:127.0.0.1:38313_solr) [n:127.0.0.1:38313_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2295574 INFO (zkCallback-2523-thread-1-processing-n:127.0.0.1:50797_solr) [n:127.0.0.1:50797_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2295574 INFO (zkCallback-2508-thread-1-processing-n:127.0.0.1:43659_solr) [n:127.0.0.1:43659_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2295574 INFO (zkCallback-2514-thread-1-processing-n:127.0.0.1:48006_solr) [n:127.0.0.1:48006_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2295575 INFO (zkCallback-2515-thread-1-processing-n:127.0.0.1:39448_solr) [n:127.0.0.1:39448_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2295575 INFO (zkCallback-2503-thread-2-processing-n:127.0.0.1:50764_solr) [n:127.0.0.1:50764_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296005 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2296005 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2296005 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:48006/solr/facetcollection_shard3_replica2/
[junit4] 2> 2296006 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard3_replica2 url=https://127.0.0.1:48006/solr START replicas=[https://127.0.0.1:39448/solr/facetcollection_shard3_replica1/] nUpdates=100
[junit4] 2> 2296010 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2296011 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2296011 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:50797/solr/facetcollection_shard2_replica1/
[junit4] 2> 2296011 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard2_replica1 url=https://127.0.0.1:50797/solr START replicas=[https://127.0.0.1:38313/solr/facetcollection_shard2_replica2/] nUpdates=100
[junit4] 2> 2296011 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2296011 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2296011 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:43659/solr/facetcollection_shard1_replica1/
[junit4] 2> 2296011 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard1_replica1 url=https://127.0.0.1:43659/solr START replicas=[https://127.0.0.1:50764/solr/facetcollection_shard1_replica2/] nUpdates=100
[junit4] 2> 2296015 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard3_replica2 url=https://127.0.0.1:48006/solr DONE. We have no versions. sync failed.
[junit4] 2> 2296015 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard1_replica1 url=https://127.0.0.1:43659/solr DONE. We have no versions. sync failed.
[junit4] 2> 2296015 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard2_replica1 url=https://127.0.0.1:50797/solr DONE. We have no versions. sync failed.
[junit4] 2> 2296116 INFO (qtp67625081-16727) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.c.S.Request [facetcollection_shard1_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=9
[junit4] 2> 2296118 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2296118 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 2296122 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:43659/solr/facetcollection_shard1_replica1/ shard1
[junit4] 2> 2296131 INFO (qtp128633871-16764) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.c.S.Request [facetcollection_shard2_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=13
[junit4] 2> 2296131 INFO (qtp733534405-16791) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.c.S.Request [facetcollection_shard3_replica1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=13
[junit4] 2> 2296131 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2296131 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 2296132 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2296132 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 2296136 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:50797/solr/facetcollection_shard2_replica1/ shard2
[junit4] 2> 2296136 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:48006/solr/facetcollection_shard3_replica2/ shard3
[junit4] 2> 2296282 INFO (zkCallback-2516-thread-1-processing-n:127.0.0.1:38313_solr) [n:127.0.0.1:38313_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296282 INFO (zkCallback-2514-thread-1-processing-n:127.0.0.1:48006_solr) [n:127.0.0.1:48006_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296282 INFO (zkCallback-2523-thread-1-processing-n:127.0.0.1:50797_solr) [n:127.0.0.1:50797_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296282 INFO (zkCallback-2515-thread-1-processing-n:127.0.0.1:39448_solr) [n:127.0.0.1:39448_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296282 INFO (zkCallback-2508-thread-1-processing-n:127.0.0.1:43659_solr) [n:127.0.0.1:43659_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296283 INFO (zkCallback-2503-thread-3-processing-n:127.0.0.1:50764_solr) [n:127.0.0.1:50764_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296298 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2296298 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2296300 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.config=solrconfig-blockjoinfacetcomponent.xml&property.schema=schema-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard2_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard2&wt=javabin&version=2} status=0 QTime=2146
[junit4] 2> 2296301 INFO (qtp197172838-16753) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.config=solrconfig-blockjoinfacetcomponent.xml&property.schema=schema-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard3_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard3&wt=javabin&version=2} status=0 QTime=2104
[junit4] 2> 2296331 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2296333 INFO (qtp1768208227-16738) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.config=solrconfig-blockjoinfacetcomponent.xml&property.schema=schema-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard1_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard1&wt=javabin&version=2} status=0 QTime=2181
[junit4] 2> 2296440 INFO (zkCallback-2516-thread-1-processing-n:127.0.0.1:38313_solr) [n:127.0.0.1:38313_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296440 INFO (zkCallback-2514-thread-1-processing-n:127.0.0.1:48006_solr) [n:127.0.0.1:48006_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296440 INFO (zkCallback-2515-thread-1-processing-n:127.0.0.1:39448_solr) [n:127.0.0.1:39448_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296441 INFO (zkCallback-2508-thread-1-processing-n:127.0.0.1:43659_solr) [n:127.0.0.1:43659_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296447 INFO (zkCallback-2523-thread-1-processing-n:127.0.0.1:50797_solr) [n:127.0.0.1:50797_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296448 INFO (zkCallback-2503-thread-1-processing-n:127.0.0.1:50764_solr) [n:127.0.0.1:50764_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296451 INFO (qtp128633871-16762) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.config=solrconfig-blockjoinfacetcomponent.xml&property.schema=schema-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard2_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard2&wt=javabin&version=2} status=0 QTime=2246
[junit4] 2> 2296484 INFO (qtp67625081-16724) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.config=solrconfig-blockjoinfacetcomponent.xml&property.schema=schema-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard1_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard1&wt=javabin&version=2} status=0 QTime=2330
[junit4] 2> 2296497 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.config=solrconfig-blockjoinfacetcomponent.xml&property.schema=schema-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard3_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard3&wt=javabin&version=2} status=0 QTime=2318
[junit4] 2> 2296508 INFO (qtp1768208227-16735) [n:127.0.0.1:43659_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 2296599 INFO (zkCallback-2514-thread-1-processing-n:127.0.0.1:48006_solr) [n:127.0.0.1:48006_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296599 INFO (zkCallback-2516-thread-1-processing-n:127.0.0.1:38313_solr) [n:127.0.0.1:38313_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296599 INFO (zkCallback-2515-thread-1-processing-n:127.0.0.1:39448_solr) [n:127.0.0.1:39448_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296599 INFO (zkCallback-2523-thread-1-processing-n:127.0.0.1:50797_solr) [n:127.0.0.1:50797_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296600 INFO (zkCallback-2503-thread-1-processing-n:127.0.0.1:50764_solr) [n:127.0.0.1:50764_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2296602 INFO (zkCallback-2508-thread-1-processing-n:127.0.0.1:43659_solr) [n:127.0.0.1:43659_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2297509 INFO (qtp1768208227-16735) [n:127.0.0.1:43659_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&property.config=solrconfig-blockjoinfacetcomponent.xml&property.schema=schema-blockjoinfacetcomponent.xml&collection.configName=solrCloudCollectionConfig&name=facetcollection&action=CREATE&numShards=3&wt=javabin&version=2} status=0 QTime=3726
[junit4] 2> 2297601 INFO (TEST-BlockJoinFacetDistribTest.testBJQFacetComponent-seed#[FF863684FC708662]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBJQFacetComponent
[junit4] 2> 2297711 INFO (qtp128633871-16765) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1551266311998275584&distrib.from=https://127.0.0.1:50797/solr/facetcollection_shard2_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1551266311998275584)} 0 23
[junit4] 2> 2297725 INFO (qtp733534405-16800) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1551266312011907072&distrib.from=https://127.0.0.1:48006/solr/facetcollection_shard3_replica2/&wt=javabin&version=2}{deleteByQuery=*:* (-1551266312011907072)} 0 13
[junit4] 2> 2297725 INFO (qtp197172838-16748) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:50797/solr/facetcollection_shard2_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1551266312011907072)} 0 71
[junit4] 2> 2297736 INFO (qtp67625081-16720) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1551266312020295680&distrib.from=https://127.0.0.1:43659/solr/facetcollection_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1551266312020295680)} 0 9
[junit4] 2> 2297737 INFO (qtp1768208227-16732) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:50797/solr/facetcollection_shard2_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1551266312020295680)} 0 75
[junit4] 2> 2297737 INFO (qtp1435289123-16773) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1551266311998275584)} 0 125
[junit4] 2> 2297797 INFO (qtp128633871-16758) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:50797/solr/facetcollection_shard2_replica1/&wt=javabin&version=2}{add=[2 (1551266312145076224), 3 (1551266312146124800), 4 (1551266312147173376), 6 (1551266312147173377), 7 (1551266312147173378), 9 (1551266312147173379), 12 (1551266312148221952), 15 (1551266312148221953), 20 (1551266312148221954), 22 (1551266312148221955), ... (11 adds)]} 0 9
[junit4] 2> 2297798 INFO (qtp1435289123-16775) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2 (1551266312145076224), 3 (1551266312146124800), 4 (1551266312147173376), 6 (1551266312147173377), 7 (1551266312147173378), 9 (1551266312147173379), 12 (1551266312148221952), 15 (1551266312148221953), 20 (1551266312148221954), 22 (1551266312148221955), ... (11 adds)]} 0 16
[junit4] 2> 2297798 INFO (qtp733534405-16744) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:48006/solr/facetcollection_shard3_replica2/&wt=javabin&version=2}{add=[5 (1551266312153464832), 17 (1551266312154513408), 18 (1551266312154513409), 19 (1551266312154513410), 21 (1551266312154513411), 23 (1551266312154513412), 25 (1551266312159756288)]} 0 5
[junit4] 2> 2297799 INFO (qtp197172838-16748) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[5 (1551266312153464832), 17 (1551266312154513408), 18 (1551266312154513409), 19 (1551266312154513410), 21 (1551266312154513411), 23 (1551266312154513412), 25 (1551266312159756288)]} 0 10
[junit4] 2> 2297800 INFO (qtp67625081-16723) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:43659/solr/facetcollection_shard1_replica1/&wt=javabin&version=2}{add=[0 (1551266312140881920), 1 (1551266312146124800), 8 (1551266312147173376), 10 (1551266312153464832), 11 (1551266312153464833), 13 (1551266312153464834), 14 (1551266312153464835), 16 (1551266312162902016), 24 (1551266312162902017), 27 (1551266312162902018), ... (11 adds)]} 0 13
[junit4] 2> 2297801 INFO (qtp1768208227-16736) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0 (1551266312140881920), 1 (1551266312146124800), 8 (1551266312147173376), 10 (1551266312153464832), 11 (1551266312153464833), 13 (1551266312153464834), 14 (1551266312153464835), 16 (1551266312162902016), 24 (1551266312162902017), 27 (1551266312162902018), ... (11 adds)]} 0 23
[junit4] 2> 2297809 INFO (qtp1435289123-16770) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2297810 INFO (qtp1435289123-16770) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@68fdf3fd
[junit4] 2> 2297810 INFO (qtp67625081-16726) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2297810 INFO (qtp67625081-16726) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@68ae989d
[junit4] 2> 2297812 INFO (OverseerCollectionConfigSetProcessor-96954144056541194-127.0.0.1:50764_solr-n_0000000000) [n:127.0.0.1:50764_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 2297841 INFO (qtp1435289123-16770) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@9be95bd[facetcollection_shard2_replica1] main]
[junit4] 2> 2297842 INFO (qtp1435289123-16770) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2297842 INFO (searcherExecutor-8144-thread-1-processing-n:127.0.0.1:50797_solr x:facetcollection_shard2_replica1 s:shard2 c:facetcollection r:core_node3) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.c.SolrCore [facetcollection_shard2_replica1] Registered new searcher Searcher@9be95bd[facetcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C235)))}
[junit4] 2> 2297842 INFO (qtp1435289123-16770) [n:127.0.0.1:50797_solr c:facetcollection s:shard2 r:core_node3 x:facetcollection_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:50797/solr/facetcollection_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 32
[junit4] 2> 2297843 INFO (qtp128633871-16761) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2297843 INFO (qtp128633871-16761) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@3cd0010f
[junit4] 2> 2297864 INFO (qtp67625081-16726) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@65c345a8[facetcollection_shard1_replica2] main]
[junit4] 2> 2297864 INFO (qtp67625081-16726) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2297878 INFO (searcherExecutor-8146-thread-1-processing-n:127.0.0.1:50764_solr x:facetcollection_shard1_replica2 s:shard1 c:facetcollection r:core_node1) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.c.SolrCore [facetcollection_shard1_replica2] Registered new searcher Searcher@65c345a8[facetcollection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C239)))}
[junit4] 2> 2297878 INFO (qtp67625081-16726) [n:127.0.0.1:50764_solr c:facetcollection s:shard1 r:core_node1 x:facetcollection_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:50797/solr/facetcollection_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 67
[junit4] 2> 2297887 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2297887 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5413b3a3
[junit4] 2> 2297894 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@40f1a064[facetcollection_shard3_replica1] main]
[junit4] 2> 2297894 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2297983 INFO (searcherExecutor-8147-thread-1-processing-n:127.0.0.1:39448_solr x:facetcollection_shard3_replica1 s:shard3 c:facetcollection r:core_node6) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.c.SolrCore [facetcollection_shard3_replica1] Registered new searcher Searcher@40f1a064[facetcollection_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C151)))}
[junit4] 2> 2297983 INFO (qtp733534405-16789) [n:127.0.0.1:39448_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica1] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:50797/solr/facetcollection_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 99
[junit4] 2> 2297984 INFO (qtp1768208227-16733) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2297984 INFO (qtp1768208227-16733) [n:127.0.0.1:43659_solr c:facetcollection s:shard1 r:core_node2 x:facetcollection_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@762b29a1
[junit4] 2> 2297984 INFO (qtp128633871-16761) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@7fecddda[facetcollection_shard2_replica2] main]
[junit4] 2> 2297984 INFO (qtp128633871-16761) [n:127.0.0.1:38313_solr c:facetcollection s:shard2 r:core_node5 x:facetcollection_shard2_replica2] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2297985 INFO (qtp197172838-16745) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2297985 INFO (qtp197172838-16745) [n:127.0.0.1:48006_solr c:facetcollection s:shard3 r:core_node4 x:facetcollection_shard3_replica2] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apach
[...truncated too long message...]
127.0.0.1:33148 33148
[junit4] 2> 2299931 INFO (Thread-5399) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33148 33148
[junit4] 2> 2299932 WARN (Thread-5399) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/aliases.json
[junit4] 2> 6 /solr/security.json
[junit4] 2> 6 /solr/configs/solrCloudCollectionConfig
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/clusterstate.json
[junit4] 2> 7 /solr/clusterprops.json
[junit4] 2> 6 /solr/collections/facetcollection/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 11 /solr/overseer/queue
[junit4] 2> 7 /solr/live_nodes
[junit4] 2> 7 /solr/collections
[junit4] 2> 4 /solr/overseer/collection-queue-work
[junit4] 2> 3 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> 2299933 INFO (SUITE-BlockJoinFacetDistribTest-seed#[FF863684FC708662]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> Nov 17, 2016 5:14:01 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> 2300292 WARN (OverseerCollectionConfigSetProcessor-96954144056541199-127.0.0.1:48006_solr-n_0000000004) [n:127.0.0.1:48006_solr ] o.a.s.c.OverseerTaskProcessor Overseer cannot talk to ZK
[junit4] 2> Nov 17, 2016 5:14:22 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at org.apache.solr.search.join.BlockJoinFacetDistribTest:
[junit4] 2> 1) Thread[id=16926, name=OverseerHdfsCoreFailoverThread-96954144056541199-127.0.0.1:48006_solr-n_0000000004, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
[junit4] 2> at java.lang.Thread.sleep(Native Method)
[junit4] 2> at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:137)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> Nov 17, 2016 5:14:22 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=16926, name=OverseerHdfsCoreFailoverThread-96954144056541199-127.0.0.1:48006_solr-n_0000000004, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
[junit4] 2> Nov 17, 2016 5:14:22 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: All leaked threads terminated.
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {type_s=FST50, COLOR_s=BlockTreeOrds(blocksize=128), SIZE_s=BlockTreeOrds(blocksize=128), _version_=FST50, _root_=FST50, BRAND_s=BlockTreeOrds(blocksize=128), id=BlockTreeOrds(blocksize=128)}, docValues:{}, maxPointsInLeafNode=1665, maxMBSortInHeap=7.972896333436938, sim=RandomSimilarity(queryNorm=true,coord=crazy): {}, locale=ca, timezone=Europe/Nicosia
[junit4] 2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8.0_102 (64-bit)/cpus=4,threads=1,free=129428016,total=530055168
[junit4] 2> NOTE: All tests run in this JVM: [SSLMigrationTest, BasicAuthIntegrationTest, NumericFieldsTest, TestPHPSerializedResponseWriter, TestBinaryResponseWriter, TestValueSourceCache, TestFastLRUCache, ZkNodePropsTest, DistributedSpellCheckComponentTest, SimpleMLTQParserTest, CdcrUpdateLogTest, TestRandomFaceting, TestSolrCloudSnapshots, TestCollationFieldDocValues, CheckHdfsIndexTest, TestPivotHelperCode, DeleteShardTest, CreateCollectionCleanupTest, TestSchemaResource, TestRemoteStreaming, TestRandomDVFaceting, CollectionTooManyReplicasTest, ReplicationFactorTest, BasicZkTest, TestCloudManagedSchema, TestManagedSchemaThreadSafety, PreAnalyzedFieldManagedSchemaCloudTest, TestRequestForwarding, TestScoreJoinQPScore, TestFaceting, TestBlobHandler, TestReplicationHandler, TestGeoJSONResponseWriter, TestReplicationHandlerBackup, HdfsRecoveryZkTest, TestDistributedSearch, BlockDirectoryTest, TestExclusionRuleCollectionAccess, CursorPagingTest, TestNonDefinedSimilarityFactory, RegexBoostProcessorTest, AnalysisAfterCoreReloadTest, SegmentsInfoRequestHandlerTest, TestFieldCacheSortRandom, HighlighterConfigTest, HdfsLockFactoryTest, PathHierarchyTokenizerFactoryTest, TestFastWriter, SharedFSAutoReplicaFailoverTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest, DistributedExpandComponentTest, TestRTimerTree, TestCopyFieldCollectionResource, TestCollapseQParserPlugin, OverseerStatusTest, TestXmlQParserPlugin, TestDocumentBuilder, BJQParserTest, SortSpecParsingTest, DateRangeFieldTest, MultiThreadedOCPTest, SynonymTokenizerTest, TestSolrDeletionPolicy2, TestOmitPositions, ShufflingReplicaListTransformerTest, ClassificationUpdateProcessorFactoryTest, TestDocSet, TestMacros, TestFieldTypeCollectionResource, BitVectorTest, DisMaxRequestHandlerTest, TestFunctionQuery, TestStressRecovery, NotRequiredUniqueKeyTest, TestMinMaxOnMultiValuedField, HdfsBasicDistributedZkTest, RecoveryAfterSoftCommitTest, TestAtomicUpdateErrorCases, TestStressLucene, ScriptEngineTest, TestNRTOpen, TestConfigSetImmutable, TestLegacyFieldCache, TestRawResponseWriter, TestHashQParserPlugin, CloudExitableDirectoryReaderTest, TestUseDocValuesAsStored2, TestAnalyzeInfixSuggestions, TestReRankQParserPlugin, TestEmbeddedSolrServerConstructors, CurrencyFieldOpenExchangeTest, TestSolrConfigHandler, BasicDistributedZkTest, TestLeaderElectionZkExpiry, DistribDocExpirationUpdateProcessorTest, SolrRequestParserTest, DistributedFacetPivotLongTailTest, CdcrReplicationDistributedZkTest, UniqFieldsUpdateProcessorFactoryTest, TestCorePropertiesReload, XsltUpdateRequestHandlerTest, PeerSyncTest, DistributedVersionInfoTest, ZkStateReaderTest, TestRandomRequestDistribution, OpenCloseCoreStressTest, OverseerTest, LeaderElectionIntegrationTest, ClusterStateUpdateTest, TestRecovery, TestRealTimeGet, TestJoin, TestCoreContainer, SimpleFacetsTest, SolrCoreTest, SpellCheckComponentTest, TestGroupingSearch, QueryElevationComponentTest, ConvertedLegacyTest, TestSort, DirectUpdateHandlerTest, TestBadConfig, TestIndexSearcher, SoftAutoCommitTest, SpellCheckCollatorTest, TestFoldingMultitermQuery, SuggesterTSTTest, TestTrie, SuggesterWFSTTest, PolyFieldTest, SchemaVersionSpecificBehaviorTest, QueryEqualityTest, DocValuesMultiTest, SolrInfoMBeanTest, DebugComponentTest, CacheHeaderTest, LukeRequestHandlerTest, XmlUpdateRequestHandlerTest, DocumentBuilderTest, RequiredFieldsTest, FastVectorHighlighterTest, SolrPluginUtilsTest, IndexSchemaTest, TestCollationField, ReturnFieldsTest, TestAnalyzedSuggestions, BinaryUpdateRequestHandlerTest, CSVRequestHandlerTest, SearchHandlerTest, SOLR749Test, AlternateDirectoryTest, TestSolrIndexConfig, TestQuerySenderNoQuery, CopyFieldTest, BadComponentTest, TestMergePolicyConfig, TestBinaryField, TestConfig, OutputWriterTest, TestFuzzyAnalyzedSuggestions, ExternalFileFieldSortTest, TestSolrCoreProperties, DirectSolrConnectionTest, TestLuceneMatchVersion, TestCodecSupport, TestXIncludeConfig, EchoParamsTest, TestSweetSpotSimilarityFactory, TestPerFieldSimilarity, TestLMJelinekMercerSimilarityFactory, TestIBSimilarityFactory, TestBM25SimilarityFactory, TestJmxMonitoredMap, ResourceLoaderTest, DateMathParserTest, ChaosMonkeyNothingIsSafeTest, UUIDFieldTest, TestHighlightDedupGrouping, TestTolerantSearch, ActionThrottleTest, AssignTest, AsyncCallRequestStatusResponseTest, CdcrVersionReplicationTest, ConcurrentDeleteAndCreateCollectionTest, ConnectionManagerTest, DeleteInactiveReplicaTest, DeleteLastCustomShardedReplicaTest, ForceLeaderTest, ShardSplitTest, TestSQLHandler, DistributedFacetPivotSmallAdvancedTest, DistributedFacetPivotSmallTest, DistributedQueryComponentCustomSortTest, SuggestComponentTest, SmileWriterTest, TestBinaryResponseWriter, TestCustomDocTransformer, TestGraphMLResponseWriter, TestSubQueryTransformerCrossCore, TestManagedResource, TestRestManager, TestDynamicFieldResource, TestFieldResource, TestSchemaNameResource, TestSchemaVersionResource, TestSerializedLuceneMatchVersion, TestUniqueKeyFieldResource, TestManagedStopFilterFactory, TestManagedSynonymFilterFactory, BooleanFieldTest, EnumFieldTest, SpatialRPTFieldTypeTest, AnalyticsMergeStrategyTest, CursorMarkTest, TestFieldSortValues, TestFilteredDocIdSet, TestGraphTermsQParserPlugin, TestMissingGroups, TestSearcherReuse, TestSmileRequest, TestSolr4Spatial2, TestStandardQParsers, TestStressUserVersions, TestTrieFacet, TestXmlQParser, TestJsonFacetRefinement, TestOrdValues, TestSortByMinMaxFunction, BlockJoinFacetDistribTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BlockJoinFacetDistribTest -Dtests.seed=FF863684FC708662 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=ca -Dtests.timezone=Europe/Nicosia -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J0 | BlockJoinFacetDistribTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.search.join.BlockJoinFacetDistribTest:
[junit4] > 1) Thread[id=16926, name=OverseerHdfsCoreFailoverThread-96954144056541199-127.0.0.1:48006_solr-n_0000000004, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
[junit4] > at java.lang.Thread.sleep(Native Method)
[junit4] > at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:137)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > at __randomizedtesting.SeedInfo.seed([FF863684FC708662]:0)
[junit4] Completed [614/653 (1!)] on J0 in 29.37s, 1 test, 1 error <<< FAILURES!
[...truncated 60814 lines...]