You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2017/01/14 01:00:20 UTC
[JENKINS-EA] Lucene-Solr-6.x-Linux (64bit/jdk-9-ea+147) - Build #
2662 - Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Linux/2662/
Java: 64bit/jdk-9-ea+147 -XX:-UseCompressedOops -XX:+UseParallelGC
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=25184, name=OverseerHdfsCoreFailoverThread-97278684641558541-127.0.0.1:46671_solr-n_0000000002, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.] at java.base/java.lang.Thread.sleep(Native Method) at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:139) at java.base/java.lang.Thread.run(Thread.java:844)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.search.join.BlockJoinFacetDistribTest:
1) Thread[id=25184, name=OverseerHdfsCoreFailoverThread-97278684641558541-127.0.0.1:46671_solr-n_0000000002, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
at java.base/java.lang.Thread.sleep(Native Method)
at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:139)
at java.base/java.lang.Thread.run(Thread.java:844)
at __randomizedtesting.SeedInfo.seed([60F981BE3E6F147D]:0)
Build Log:
[...truncated 13008 lines...]
[junit4] Suite: org.apache.solr.search.join.BlockJoinFacetDistribTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/init-core-data-001
[junit4] 2> 2160453 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 2160454 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 6 servers in /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001
[junit4] 2> 2160454 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2160455 INFO (Thread-3294) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2160455 INFO (Thread-3294) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2160555 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:41471
[junit4] 2> 2160564 INFO (jetty-launcher-5785-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2160566 INFO (jetty-launcher-5785-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2160568 INFO (jetty-launcher-5785-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2160575 INFO (jetty-launcher-5785-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5147246{/solr,null,AVAILABLE}
[junit4] 2> 2160576 INFO (jetty-launcher-5785-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@16208f6e{SSL,[ssl, http/1.1]}{127.0.0.1:46464}
[junit4] 2> 2160576 INFO (jetty-launcher-5785-thread-1) [ ] o.e.j.s.Server Started @2163327ms
[junit4] 2> 2160576 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46464}
[junit4] 2> 2160576 ERROR (jetty-launcher-5785-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2160577 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2160577 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2160577 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2160577 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-14T00:48:49.344334Z
[junit4] 2> 2160585 INFO (jetty-launcher-5785-thread-5) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2160586 INFO (jetty-launcher-5785-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2160586 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2160619 INFO (jetty-launcher-5785-thread-6) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2160620 INFO (jetty-launcher-5785-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6ef7b8b3{/solr,null,AVAILABLE}
[junit4] 2> 2160621 INFO (jetty-launcher-5785-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@fade67f{SSL,[ssl, http/1.1]}{127.0.0.1:36207}
[junit4] 2> 2160621 INFO (jetty-launcher-5785-thread-2) [ ] o.e.j.s.Server Started @2163372ms
[junit4] 2> 2160621 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36207}
[junit4] 2> 2160621 ERROR (jetty-launcher-5785-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2160621 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2160622 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2160622 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2160622 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-14T00:48:49.389129Z
[junit4] 2> 2160622 INFO (jetty-launcher-5785-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@631cc431{/solr,null,AVAILABLE}
[junit4] 2> 2160623 INFO (jetty-launcher-5785-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7ede4b9d{SSL,[ssl, http/1.1]}{127.0.0.1:46671}
[junit4] 2> 2160623 INFO (jetty-launcher-5785-thread-3) [ ] o.e.j.s.Server Started @2163374ms
[junit4] 2> 2160623 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46671}
[junit4] 2> 2160623 ERROR (jetty-launcher-5785-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2160623 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2160623 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2160623 INFO (jetty-launcher-5785-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@16e32066{/solr,null,AVAILABLE}
[junit4] 2> 2160623 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2160624 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-14T00:48:49.391120Z
[junit4] 2> 2160624 INFO (jetty-launcher-5785-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@761303b0{SSL,[ssl, http/1.1]}{127.0.0.1:44650}
[junit4] 2> 2160624 INFO (jetty-launcher-5785-thread-4) [ ] o.e.j.s.Server Started @2163375ms
[junit4] 2> 2160624 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44650}
[junit4] 2> 2160624 ERROR (jetty-launcher-5785-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2160625 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2160625 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2160625 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2160625 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-14T00:48:49.392239Z
[junit4] 2> 2160626 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2160626 INFO (jetty-launcher-5785-thread-5) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7c3eaebe{/solr,null,AVAILABLE}
[junit4] 2> 2160627 INFO (jetty-launcher-5785-thread-5) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6655ae55{SSL,[ssl, http/1.1]}{127.0.0.1:35023}
[junit4] 2> 2160627 INFO (jetty-launcher-5785-thread-5) [ ] o.e.j.s.Server Started @2163378ms
[junit4] 2> 2160627 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35023}
[junit4] 2> 2160627 ERROR (jetty-launcher-5785-thread-5) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2160627 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2160627 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2160627 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2160627 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-14T00:48:49.394649Z
[junit4] 2> 2160630 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2160632 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2160634 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41471/solr
[junit4] 2> 2160634 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2160635 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2160639 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 0x1599a72c2470002, 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.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 2160640 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 0x1599a72c2470006, 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.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 2160640 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 0x1599a72c2470005, 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.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 2160655 INFO (jetty-launcher-5785-thread-6) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@28a48d73{/solr,null,AVAILABLE}
[junit4] 2> 2160656 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2160657 INFO (jetty-launcher-5785-thread-6) [ ] o.e.j.s.AbstractConnector Started ServerConnector@60f31866{SSL,[ssl, http/1.1]}{127.0.0.1:34681}
[junit4] 2> 2160657 INFO (jetty-launcher-5785-thread-6) [ ] o.e.j.s.Server Started @2163408ms
[junit4] 2> 2160657 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34681}
[junit4] 2> 2160657 ERROR (jetty-launcher-5785-thread-6) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2160659 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2160659 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2160660 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2160660 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2160660 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-14T00:48:49.427174Z
[junit4] 2> 2160665 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41471/solr
[junit4] 2> 2160666 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2160669 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41471/solr
[junit4] 2> 2160673 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41471/solr
[junit4] 2> 2160673 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2160677 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41471/solr
[junit4] 2> 2160679 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2160679 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 0x1599a72c247000a, 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.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 2160680 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:46464_solr
[junit4] 2> 2160681 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.c.Overseer Overseer (id=97278684641558535-127.0.0.1:46464_solr-n_0000000000) starting
[junit4] 2> 2160688 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2160691 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46464_solr
[junit4] 2> 2160693 INFO (zkCallback-5810-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2160695 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36207_solr
[junit4] 2> 2160695 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2160697 INFO (zkCallback-5795-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2160698 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41471/solr
[junit4] 2> 2160699 INFO (zkCallback-5795-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2160700 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 0x1599a72c2470010, 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.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 2160702 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2160705 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2160708 INFO (zkCallback-5811-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2160709 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34681_solr
[junit4] 2> 2160709 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46671_solr
[junit4] 2> 2160711 INFO (zkCallback-5795-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 2160711 INFO (zkCallback-5812-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 2160711 INFO (zkCallback-5819-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 2160713 INFO (zkCallback-5810-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2160713 INFO (zkCallback-5811-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 2160714 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44650_solr
[junit4] 2> 2160716 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5)
[junit4] 2> 2160717 INFO (zkCallback-5795-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2160717 INFO (zkCallback-5812-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2160718 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node1/.
[junit4] 2> 2160720 INFO (zkCallback-5811-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2160721 INFO (zkCallback-5819-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2160723 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35023_solr
[junit4] 2> 2160724 INFO (zkCallback-5811-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2160724 INFO (zkCallback-5821-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2160724 INFO (zkCallback-5795-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2160724 INFO (zkCallback-5812-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2160724 INFO (zkCallback-5819-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2160725 INFO (zkCallback-5810-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 2160729 INFO (zkCallback-5810-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (6)
[junit4] 2> 2160731 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node3/.
[junit4] 2> 2160738 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node4/.
[junit4] 2> 2160739 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node6/.
[junit4] 2> 2160740 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node2/.
[junit4] 2> 2160743 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node5/.
[junit4] 2> 2161105 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (6)
[junit4] 2> 2161106 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41471/solr ready
[junit4] 2> 2161927 INFO (qtp2144423356-24992) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&collection.configName=solrCloudCollectionConfig&name=facetcollection&action=CREATE&numShards=3&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2161928 INFO (OverseerThreadFactory-8684-thread-1) [ ] o.a.s.c.CreateCollectionCmd Create collection facetcollection
[junit4] 2> 2162042 INFO (qtp2144423356-24993) [ ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-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> 2162087 INFO (qtp1663415689-24976) [ ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-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> 2162087 INFO (qtp351607826-24963) [ ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-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> 2162087 INFO (qtp673341061-25001) [ ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-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> 2162090 INFO (qtp1516197574-24997) [ ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-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> 2162100 INFO (qtp1331257531-24996) [ ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-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> 2162203 INFO (zkCallback-5795-thread-1) [ ] 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> 2162203 INFO (zkCallback-5812-thread-1) [ ] 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> 2162203 INFO (zkCallback-5810-thread-1) [ ] 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> 2162203 INFO (zkCallback-5821-thread-1) [ ] 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> 2162203 INFO (zkCallback-5811-thread-1) [ ] 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> 2162203 INFO (zkCallback-5819-thread-1) [ ] 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> 2163052 INFO (qtp2144423356-24993) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2163058 INFO (qtp2144423356-24993) [ ] o.a.s.s.IndexSchema [facetcollection_shard2_replica1] Schema name=test
[junit4] 2> 2163060 WARN (qtp2144423356-24993) [ ] 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> 2163061 INFO (qtp2144423356-24993) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2163061 INFO (qtp2144423356-24993) [ ] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard2_replica1' using configuration from collection facetcollection
[junit4] 2> 2163062 INFO (qtp2144423356-24993) [ ] o.a.s.c.SolrCore [[facetcollection_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node2/facetcollection_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node2/./facetcollection_shard2_replica1/data/]
[junit4] 2> 2163072 INFO (qtp2144423356-24993) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2163072 INFO (qtp2144423356-24993) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2163074 INFO (qtp2144423356-24993) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2163074 INFO (qtp2144423356-24993) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2163075 INFO (qtp2144423356-24993) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1282e43b[facetcollection_shard2_replica1] main]
[junit4] 2> 2163075 INFO (qtp2144423356-24993) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2163075 INFO (qtp2144423356-24993) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2163075 INFO (searcherExecutor-8697-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard2_replica1] Registered new searcher Searcher@1282e43b[facetcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2163076 INFO (qtp2144423356-24993) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556458957012205568
[junit4] 2> 2163080 INFO (qtp2144423356-24993) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms
[junit4] 2> 2163099 INFO (qtp1516197574-24997) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2163137 INFO (qtp673341061-25001) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2163137 INFO (qtp1663415689-24976) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2163140 INFO (qtp1331257531-24996) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2163140 INFO (qtp1516197574-24997) [ ] o.a.s.s.IndexSchema [facetcollection_shard1_replica1] Schema name=test
[junit4] 2> 2163144 WARN (qtp1516197574-24997) [ ] 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> 2163145 INFO (qtp1516197574-24997) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2163146 INFO (qtp1516197574-24997) [ ] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard1_replica1' using configuration from collection facetcollection
[junit4] 2> 2163148 INFO (qtp673341061-25001) [ ] o.a.s.s.IndexSchema [facetcollection_shard1_replica2] Schema name=test
[junit4] 2> 2163149 INFO (qtp1516197574-24997) [ ] o.a.s.c.SolrCore [[facetcollection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node5/facetcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node5/./facetcollection_shard1_replica1/data/]
[junit4] 2> 2163149 INFO (qtp351607826-24963) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2163150 INFO (qtp1331257531-24996) [ ] o.a.s.s.IndexSchema [facetcollection_shard2_replica2] Schema name=test
[junit4] 2> 2163587 INFO (qtp1663415689-24976) [ ] o.a.s.s.IndexSchema [facetcollection_shard3_replica1] Schema name=test
[junit4] 2> 2163589 INFO (zkCallback-5811-thread-1) [ ] 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> 2163589 INFO (zkCallback-5810-thread-1) [ ] 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> 2163589 INFO (zkCallback-5821-thread-1) [ ] 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> 2163589 INFO (zkCallback-5812-thread-1) [ ] 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> 2163589 INFO (zkCallback-5795-thread-3) [ ] 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> 2163589 INFO (zkCallback-5819-thread-1) [ ] 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> 2163591 WARN (qtp1663415689-24976) [ ] 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> 2163591 INFO (qtp1663415689-24976) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2163593 WARN (qtp1331257531-24996) [ ] 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> 2163594 INFO (qtp1331257531-24996) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2163596 WARN (qtp673341061-25001) [ ] 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> 2163596 INFO (qtp673341061-25001) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2163597 INFO (qtp1663415689-24976) [ ] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard3_replica1' using configuration from collection facetcollection
[junit4] 2> 2163598 INFO (qtp1663415689-24976) [ ] o.a.s.c.SolrCore [[facetcollection_shard3_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node3/facetcollection_shard3_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node3/./facetcollection_shard3_replica1/data/]
[junit4] 2> 2163601 INFO (qtp1331257531-24996) [ ] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard2_replica2' using configuration from collection facetcollection
[junit4] 2> 2163602 INFO (qtp1331257531-24996) [ ] o.a.s.c.SolrCore [[facetcollection_shard2_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node4/facetcollection_shard2_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node4/./facetcollection_shard2_replica2/data/]
[junit4] 2> 2163605 INFO (qtp351607826-24963) [ ] o.a.s.s.IndexSchema [facetcollection_shard3_replica2] Schema name=test
[junit4] 2> 2163608 WARN (qtp351607826-24963) [ ] 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> 2163609 INFO (qtp351607826-24963) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2163609 INFO (qtp1516197574-24997) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2163609 INFO (qtp1516197574-24997) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2163609 INFO (qtp351607826-24963) [ ] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard3_replica2' using configuration from collection facetcollection
[junit4] 2> 2163610 INFO (qtp351607826-24963) [ ] o.a.s.c.SolrCore [[facetcollection_shard3_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node1/facetcollection_shard3_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node1/./facetcollection_shard3_replica2/data/]
[junit4] 2> 2163610 INFO (qtp673341061-25001) [ ] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard1_replica2' using configuration from collection facetcollection
[junit4] 2> 2163611 INFO (qtp673341061-25001) [ ] o.a.s.c.SolrCore [[facetcollection_shard1_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node6/facetcollection_shard1_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node6/./facetcollection_shard1_replica2/data/]
[junit4] 2> 2163611 INFO (qtp1516197574-24997) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2163611 INFO (qtp1516197574-24997) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2163612 INFO (qtp1663415689-24976) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2163612 INFO (qtp1663415689-24976) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2163613 INFO (qtp1516197574-24997) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@361185b7[facetcollection_shard1_replica1] main]
[junit4] 2> 2163614 INFO (qtp1663415689-24976) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2163614 INFO (qtp1516197574-24997) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2163614 INFO (qtp1663415689-24976) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2163615 INFO (qtp1663415689-24976) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@24e07190[facetcollection_shard3_replica1] main]
[junit4] 2> 2163617 INFO (qtp1516197574-24997) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2163617 INFO (searcherExecutor-8701-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard1_replica1] Registered new searcher Searcher@361185b7[facetcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2163617 INFO (qtp1516197574-24997) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556458957579485184
[junit4] 2> 2163623 INFO (qtp1663415689-24976) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2163624 INFO (qtp1663415689-24976) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2163625 INFO (qtp1663415689-24976) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556458957587873792
[junit4] 2> 2163627 INFO (searcherExecutor-8702-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica1] Registered new searcher Searcher@24e07190[facetcollection_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2163629 INFO (qtp1516197574-24997) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 2163631 INFO (qtp1663415689-24976) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard3: total=2 found=1 timeoutin=9999ms
[junit4] 2> 2163632 INFO (qtp1331257531-24996) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2163633 INFO (qtp1331257531-24996) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2163635 INFO (qtp1331257531-24996) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2163635 INFO (qtp1331257531-24996) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2163636 INFO (qtp351607826-24963) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2163636 INFO (qtp351607826-24963) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2163636 INFO (qtp1331257531-24996) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@291afb78[facetcollection_shard2_replica2] main]
[junit4] 2> 2163637 INFO (qtp673341061-25001) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2163637 INFO (qtp673341061-25001) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2163638 INFO (qtp351607826-24963) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2163638 INFO (qtp351607826-24963) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2163639 INFO (qtp673341061-25001) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2163639 INFO (qtp673341061-25001) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2163639 INFO (qtp1331257531-24996) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2163639 INFO (qtp351607826-24963) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@39cd79ac[facetcollection_shard3_replica2] main]
[junit4] 2> 2163640 INFO (qtp1331257531-24996) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2163640 INFO (qtp673341061-25001) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4213350d[facetcollection_shard1_replica2] main]
[junit4] 2> 2163641 INFO (qtp1331257531-24996) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556458957604651008
[junit4] 2> 2163641 INFO (qtp351607826-24963) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2163642 INFO (qtp673341061-25001) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2163642 INFO (qtp351607826-24963) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2163642 INFO (qtp351607826-24963) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556458957605699584
[junit4] 2> 2163642 INFO (qtp673341061-25001) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2163642 INFO (searcherExecutor-8706-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard1_replica2] Registered new searcher Searcher@4213350d[facetcollection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2163643 INFO (qtp673341061-25001) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556458957606748160
[junit4] 2> 2163645 INFO (searcherExecutor-8703-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard2_replica2] Registered new searcher Searcher@291afb78[facetcollection_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2163646 INFO (searcherExecutor-8705-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica2] Registered new searcher Searcher@39cd79ac[facetcollection_shard3_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2163733 INFO (zkCallback-5821-thread-1) [ ] 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> 2163733 INFO (zkCallback-5812-thread-1) [ ] 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> 2163733 INFO (zkCallback-5819-thread-1) [ ] 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> 2163733 INFO (zkCallback-5810-thread-1) [ ] 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> 2163733 INFO (zkCallback-5811-thread-1) [ ] 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> 2163733 INFO (zkCallback-5795-thread-1) [ ] 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> 2164090 INFO (qtp2144423356-24993) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2164090 INFO (qtp2144423356-24993) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2164090 INFO (qtp2144423356-24993) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:36207/solr/facetcollection_shard2_replica1/
[junit4] 2> 2164091 INFO (qtp2144423356-24993) [ ] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard2_replica1 url=https://127.0.0.1:36207/solr START replicas=[https://127.0.0.1:44650/solr/facetcollection_shard2_replica2/] nUpdates=100
[junit4] 2> 2164091 INFO (qtp2144423356-24993) [ ] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard2_replica1 url=https://127.0.0.1:36207/solr DONE. We have no versions. sync failed.
[junit4] 2> 2164097 INFO (qtp1331257531-25013) [ ] 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=1
[junit4] 2> 2164098 INFO (qtp2144423356-24993) [ ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2164098 INFO (qtp2144423356-24993) [ ] 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> 2164102 INFO (qtp2144423356-24993) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:36207/solr/facetcollection_shard2_replica1/ shard2
[junit4] 2> 2164130 INFO (qtp1516197574-24997) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2164130 INFO (qtp1516197574-24997) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2164130 INFO (qtp1516197574-24997) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:35023/solr/facetcollection_shard1_replica1/
[junit4] 2> 2164130 INFO (qtp1516197574-24997) [ ] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard1_replica1 url=https://127.0.0.1:35023/solr START replicas=[https://127.0.0.1:34681/solr/facetcollection_shard1_replica2/] nUpdates=100
[junit4] 2> 2164131 INFO (qtp1516197574-24997) [ ] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard1_replica1 url=https://127.0.0.1:35023/solr DONE. We have no versions. sync failed.
[junit4] 2> 2164131 INFO (qtp1663415689-24976) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2164131 INFO (qtp1663415689-24976) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2164131 INFO (qtp1663415689-24976) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/
[junit4] 2> 2164132 INFO (qtp1663415689-24976) [ ] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard3_replica1 url=https://127.0.0.1:46671/solr START replicas=[https://127.0.0.1:46464/solr/facetcollection_shard3_replica2/] nUpdates=100
[junit4] 2> 2164133 INFO (qtp1663415689-24976) [ ] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard3_replica1 url=https://127.0.0.1:46671/solr DONE. We have no versions. sync failed.
[junit4] 2> 2164144 INFO (qtp673341061-25032) [ ] 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=0
[junit4] 2> 2164145 INFO (qtp1516197574-24997) [ ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2164145 INFO (qtp1516197574-24997) [ ] 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> 2164153 INFO (qtp351607826-24971) [ ] o.a.s.c.S.Request [facetcollection_shard3_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 2164154 INFO (qtp1663415689-24976) [ ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2164154 INFO (qtp1663415689-24976) [ ] 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> 2164155 INFO (qtp1516197574-24997) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:35023/solr/facetcollection_shard1_replica1/ shard1
[junit4] 2> 2164159 INFO (qtp1663415689-24976) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/ shard3
[junit4] 2> 2164261 INFO (zkCallback-5821-thread-1) [ ] 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> 2164261 INFO (zkCallback-5810-thread-1) [ ] 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> 2164261 INFO (zkCallback-5812-thread-1) [ ] 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> 2164261 INFO (zkCallback-5819-thread-1) [ ] 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> 2164261 INFO (zkCallback-5811-thread-1) [ ] 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> 2164262 INFO (zkCallback-5795-thread-3) [ ] 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> 2164304 INFO (qtp2144423356-24993) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2164307 INFO (qtp1516197574-24997) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2164309 INFO (qtp2144423356-24993) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-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=2266
[junit4] 2> 2164310 INFO (qtp1663415689-24976) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2164310 INFO (qtp1516197574-24997) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-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=2220
[junit4] 2> 2164313 INFO (qtp1663415689-24976) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-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=2226
[junit4] 2> 2164422 INFO (zkCallback-5812-thread-1) [ ] 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> 2164422 INFO (zkCallback-5811-thread-1) [ ] 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> 2164422 INFO (zkCallback-5819-thread-1) [ ] 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> 2164422 INFO (zkCallback-5810-thread-1) [ ] 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> 2164422 INFO (zkCallback-5795-thread-1) [ ] 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> 2164422 INFO (zkCallback-5821-thread-1) [ ] 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> 2164654 INFO (qtp1331257531-24996) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-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=2553
[junit4] 2> 2164654 INFO (qtp351607826-24963) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-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=2567
[junit4] 2> 2164654 INFO (qtp673341061-25001) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-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=2567
[junit4] 2> 2164657 INFO (qtp2144423356-24992) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 2164758 INFO (zkCallback-5795-thread-2) [ ] 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> 2164758 INFO (zkCallback-5812-thread-1) [ ] 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> 2164758 INFO (zkCallback-5819-thread-1) [ ] 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> 2164758 INFO (zkCallback-5810-thread-1) [ ] 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> 2164758 INFO (zkCallback-5811-thread-1) [ ] 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> 2164758 INFO (zkCallback-5821-thread-1) [ ] 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> 2165657 INFO (qtp2144423356-24992) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&collection.configName=solrCloudCollectionConfig&name=facetcollection&action=CREATE&numShards=3&wt=javabin&version=2} status=0 QTime=3730
[junit4] 2> 2165705 INFO (TEST-BlockJoinFacetDistribTest.testBJQFacetComponent-seed#[60F981BE3E6F147D]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBJQFacetComponent
[junit4] 2> 2165722 INFO (qtp1331257531-24999) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1556458959779397632&distrib.from=https://127.0.0.1:36207/solr/facetcollection_shard2_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1556458959779397632)} 0 2
[junit4] 2> 2165723 INFO (qtp351607826-24965) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1556458959776251904&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1556458959776251904)} 0 2
[junit4] 2> 2165723 INFO (qtp673341061-25008) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1556458959782543360&distrib.from=https://127.0.0.1:35023/solr/facetcollection_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1556458959782543360)} 0 1
[junit4] 2> 2165723 INFO (qtp2144423356-24992) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1556458959779397632)} 0 8
[junit4] 2> 2165723 INFO (qtp1516197574-25027) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1556458959782543360)} 0 5
[junit4] 2> 2165723 INFO (qtp1663415689-24979) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1556458959776251904)} 0 12
[junit4] 2> 2165737 INFO (qtp673341061-25003) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:35023/solr/facetcollection_shard1_replica1/&wt=javabin&version=2}{add=[0 (1556458959799320576), 1 (1556458959800369152)]} 0 1
[junit4] 2> 2165738 INFO (qtp1516197574-25027) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0 (1556458959799320576), 1 (1556458959800369152)]} 0 4
[junit4] 2> 2165739 INFO (qtp351607826-24970) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&wt=javabin&version=2}{add=[5 (1556458959798272000)]} 0 0
[junit4] 2> 2165739 INFO (qtp1663415689-24987) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[5 (1556458959798272000)]} 0 6
[junit4] 2> 2165742 INFO (qtp1331257531-25012) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:36207/solr/facetcollection_shard2_replica1/&wt=javabin&version=2}{add=[2 (1556458959798272000), 3 (1556458959802466304), 4 (1556458959802466305), 6 (1556458959802466306)]} 0 2
[junit4] 2> 2165742 INFO (qtp2144423356-24994) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2 (1556458959798272000), 3 (1556458959802466304), 4 (1556458959802466305), 6 (1556458959802466306)]} 0 9
[junit4] 2> 2165748 INFO (qtp1516197574-24997) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165750 INFO (qtp351607826-24971) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165750 INFO (qtp673341061-25001) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165750 INFO (qtp2144423356-24991) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165751 INFO (qtp1331257531-25012) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165752 INFO (qtp1663415689-24987) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165762 INFO (qtp351607826-24971) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@44a703b2[facetcollection_shard3_replica2] main]
[junit4] 2> 2165762 INFO (qtp1663415689-24987) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@edceb6[facetcollection_shard3_replica1] main]
[junit4] 2> 2165762 INFO (qtp673341061-25001) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5c0d4381[facetcollection_shard1_replica2] main]
[junit4] 2> 2165762 INFO (searcherExecutor-8705-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica2] Registered new searcher Searcher@44a703b2[facetcollection_shard3_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C30)))}
[junit4] 2> 2165762 INFO (qtp1516197574-24997) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7a2ba120[facetcollection_shard1_replica1] main]
[junit4] 2> 2165762 INFO (searcherExecutor-8702-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica1] Registered new searcher Searcher@edceb6[facetcollection_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C30)))}
[junit4] 2> 2165762 INFO (qtp1516197574-24997) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165762 INFO (searcherExecutor-8701-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard1_replica1] Registered new searcher Searcher@7a2ba120[facetcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C66)))}
[junit4] 2> 2165762 INFO (qtp2144423356-24991) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@594c9253[facetcollection_shard2_replica1] main]
[junit4] 2> 2165762 INFO (qtp1331257531-25012) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1105332a[facetcollection_shard2_replica2] main]
[junit4] 2> 2165762 INFO (qtp1516197574-24997) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 14
[junit4] 2> 2165763 INFO (searcherExecutor-8703-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard2_replica2] Registered new searcher Searcher@1105332a[facetcollection_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C133)))}
[junit4] 2> 2165762 INFO (qtp1663415689-24987) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165762 INFO (searcherExecutor-8706-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard1_replica2] Registered new searcher Searcher@5c0d4381[facetcollection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C66)))}
[junit4] 2> 2165762 INFO (qtp673341061-25001) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165762 INFO (qtp351607826-24971) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165763 INFO (qtp673341061-25001) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 13
[junit4] 2> 2165763 INFO (qtp351607826-24971) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 13
[junit4] 2> 2165763 INFO (qtp1663415689-24987) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 10
[junit4] 2> 2165763 INFO (qtp1331257531-25012) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165763 INFO (qtp1331257531-25012) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 12
[junit4] 2> 2165763 INFO (searcherExecutor-8697-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard2_replica1] Registered new searcher Searcher@594c9253[facetcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C133)))}
[junit4] 2> 2165763 INFO (qtp2144423356-24991) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165765 INFO (qtp2144423356-24991) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 15
[junit4] 2> 2165765 INFO (qtp1663415689-24986) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={_stateVer_=facetcollection:6&waitSearcher=false&commit=true&softCommit=true&wt=javabin&version=2}{commit=} 0 19
[junit4] 2> 2165778 INFO (qtp351607826-24965) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&wt=javabin&version=2}{add=[17 (1556458959837069312), 18 (1556458959838117888), 19 (1556458959839166464), 21 (1556458959839166465), 23 (1556458959839166466), 25 (1556458959839166467)]} 0 4
[junit4] 2> 2165778 INFO (qtp1663415689-24976) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[17 (1556458959837069312), 18 (1556458959838117888), 19 (1556458959839166464), 21 (1556458959839166465), 23 (1556458959839166466), 25 (1556458959839166467)]} 0 8
[junit4] 2> 2165779 INFO (qtp673341061-25032) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:35023/solr/facetcollection_shard1_replica1/&wt=javabin&version=2}{add=[8 (1556458959838117888), 10 (1556458959839166464), 11 (1556458959839166465), 13 (1556458959839166466), 14 (1556458959840215040), 16 (1556458959840215041), 24 (1556458959840215042)]} 0 4
[junit4] 2> 2165779 INFO (qtp1331257531-25013) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:36207/solr/facetcollection_shard2_replica1/&wt=javabin&version=2}{add=[7 (1556458959836020736), 9 (1556458959838117888), 12 (1556458959839166464), 15 (1556458959839166465), 20 (1556458959839166466), 22 (1556458959840215040), 26 (1556458959840215041)]} 0 4
[junit4] 2> 2165779 INFO (qtp1516197574-25026) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[8 (1556458959838117888), 10 (1556458959839166464), 11 (1556458959839166465), 13 (1556458959839166466), 14 (1556458959840215040), 16 (1556458959840215041), 24 (1556458959840215042)]} 0 8
[junit4] 2> 2165779 INFO (qtp2144423356-24990) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[7 (1556458959836020736), 9 (1556458959838117888), 12 (1556458959839166464), 15 (1556458959839166465), 20 (1556458959839166466), 22 (1556458959840215040), 26 (1556458959840215041)]} 0 10
[junit4] 2> 2165783 INFO (qtp673341061-25005) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165783 INFO (qtp1516197574-25022) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165783 INFO (qtp351607826-24963) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165784 INFO (qtp2144423356-24993) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165784 INFO (qtp1663415689-24979) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165785 INFO (qtp1331257531-24999) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165788 INFO (qtp2144423356-24993) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@18df0645[facetcollection_shard2_replica1] main]
[junit4] 2> 2165788 INFO (qtp1331257531-24999) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1579fcca[facetcollection_shard2_replica2] main]
[junit4] 2> 2165789 INFO (qtp1331257531-24999) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165789 INFO (qtp1331257531-24999) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 4
[junit4] 2> 2165790 INFO (searcherExecutor-8703-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard2_replica2] Registered new searcher Searcher@1579fcca[facetcollection_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C133) Uninverting(_1(6.4.0):C221)))}
[junit4] 2> 2165790 INFO (qtp1516197574-25022) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@36b0ed73[facetcollection_shard1_replica1] main]
[junit4] 2> 2165790 INFO (qtp1516197574-25022) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165790 INFO (searcherExecutor-8697-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard2_replica1] Registered new searcher Searcher@18df0645[facetcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C133) Uninverting(_1(6.4.0):C221)))}
[junit4] 2> 2165790 INFO (qtp673341061-25005) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@254c58be[facetcollection_shard1_replica2] main]
[junit4] 2> 2165790 INFO (qtp2144423356-24993) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165790 INFO (qtp2144423356-24993) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 6
[junit4] 2> 2165790 INFO (searcherExecutor-8706-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard1_replica2] Registered new searcher Searcher@254c58be[facetcollection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C66) Uninverting(_1(6.4.0):C219)))}
[junit4] 2> 2165790 INFO (qtp1516197574-25022) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 6
[junit4] 2> 2165790 INFO (searcherExecutor-8701-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard1_replica1] Registered new searcher Searcher@36b0ed73[facetcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C66) Uninverting(_1(6.4.0):C219)))}
[junit4] 2> 2165790 INFO (qtp673341061-25005) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165791 INFO (qtp351607826-24963) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2e47276f[facetcollection_shard3_replica2] main]
[junit4] 2> 2165791 INFO (qtp351607826-24963) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165791 INFO (qtp673341061-25005) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 7
[junit4] 2> 2165791 INFO (searcherExecutor-8705-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica2] Registered new searcher Searcher@2e47276f[facetcollection_shard3_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C30) Uninverting(_1(6.4.0):C192)))}
[junit4] 2> 2165791 INFO (qtp351607826-24963) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 7
[junit4] 2> 2165791 INFO (qtp1663415689-24979) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6f193abe[facetcollection_shard3_replica1] main]
[junit4] 2> 2165791 INFO (qtp1663415689-24979) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165791 INFO (searcherExecutor-8702-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica1] Registered new searcher Searcher@6f193abe[facetcollection_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C30) Uninverting(_1(6.4.0):C192)))}
[junit4] 2> 2165791 INFO (qtp1663415689-24979) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 7
[junit4] 2> 2165792 INFO (qtp1663415689-24982) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={_stateVer_=facetcollection:6&waitSearcher=false&commit=true&softCommit=true&wt=javabin&version=2}{commit=} 0 10
[junit4] 2> 2165798 INFO (qtp351607826-24971) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&wt=javabin&version=2}{add=[29 (1556458959863283712), 30 (1556458959863283713)]} 0 0
[junit4] 2> 2165798 INFO (qtp673341061-25008) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:35023/solr/facetcollection_shard1_replica1/&wt=javabin&version=2}{add=[27 (1556458959862235136), 28 (1556458959863283712)]} 0 1
[junit4] 2> 2165799 INFO (qtp1663415689-24976) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[29 (1556458959863283712), 30 (1556458959863283713)]} 0 4
[junit4] 2> 2165799 INFO (qtp1516197574-25021) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[27 (1556458959862235136), 28 (1556458959863283712)]} 0 4
[junit4] 2> 2165799 INFO (qtp1331257531-24996) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:36207/solr/facetcollection_shard2_replica1/&wt=javabin&version=2}{add=[31 (1556458959864332288)]} 0 0
[junit4] 2> 2165800 INFO (qtp2144423356-24992) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[31 (1556458959864332288)]} 0 4
[junit4] 2> 2165804 INFO (qtp673341061-25001) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165804 INFO (qtp1663415689-24986) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165804 INFO (qtp351607826-24970) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165804 INFO (qtp1331257531-25012) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165804 INFO (qtp1516197574-25027) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165807 INFO (qtp1663415689-24986) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@190057f8[facetcollection_shard3_replica1] main]
[junit4] 2> 2165807 INFO (qtp673341061-25001) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@186cd8f9[facetcollection_shard1_replica2] main]
[junit4] 2> 2165807 INFO (qtp1663415689-24986) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165807 INFO (searcherExecutor-8702-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica1] Registered new searcher Searcher@190057f8[facetcollection_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C30) Uninverting(_1(6.4.0):C192) Uninverting(_2(6.4.0):C60)))}
[junit4] 2> 2165807 INFO (qtp673341061-25001) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165807 INFO (qtp1663415689-24986) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 3
[junit4] 2> 2165807 INFO (qtp673341061-25001) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 3
[junit4] 2> 2165807 INFO (qtp351607826-24970) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5de0d4b4[facetcollection_shard3_replica2] main]
[junit4] 2> 2165807 INFO (qtp351607826-24970) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165807 INFO (searcherExecutor-8705-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica2] Registered new searcher Searcher@5de0d4b4[facetcollection_shard3_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C30) Uninverting(_1(6.4.0):C192) Uninverting(_2(6.4.0):C60)))}
[junit4] 2> 2165807 INFO (qtp351607826-24970) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&wait
[...truncated too long message...]
7278684641558541-127.0.0.1:46671_solr-n_0000000002) [ ] o.a.s.c.Overseer According to ZK I (id=97278684641558541-127.0.0.1:46671_solr-n_0000000002) am no longer a leader.
[junit4] 2> 2167429 INFO (OverseerStateUpdate-97278684641558541-127.0.0.1:46671_solr-n_0000000002) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:46671_solr
[junit4] 2> 2167430 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:41471 41471
[junit4] 2> 2172493 INFO (Thread-3294) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:41471 41471
[junit4] 2> 2172493 WARN (Thread-3294) [ ] 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> 2 /solr/overseer_elect/election/97278684641558541-127.0.0.1:46671_solr-n_0000000002
[junit4] 2> 2 /solr/overseer_elect/election/97278684641558535-127.0.0.1:46464_solr-n_0000000000
[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> 3 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> 2172494 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> Jan 14, 2017 12:49:01 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> Jan 14, 2017 12:49:21 AM 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=25184, name=OverseerHdfsCoreFailoverThread-97278684641558541-127.0.0.1:46671_solr-n_0000000002, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
[junit4] 2> at java.base/java.lang.Thread.sleep(Native Method)
[junit4] 2> at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:139)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> Jan 14, 2017 12:49:21 AM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=25184, name=OverseerHdfsCoreFailoverThread-97278684641558541-127.0.0.1:46671_solr-n_0000000002, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
[junit4] 2> Jan 14, 2017 12:49:21 AM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: All leaked threads terminated.
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {type_s=FSTOrd50, COLOR_s=PostingsFormat(name=MockRandom), SIZE_s=FST50, _version_=FSTOrd50, _root_=FSTOrd50, BRAND_s=PostingsFormat(name=MockRandom), id=PostingsFormat(name=MockRandom)}, docValues:{}, maxPointsInLeafNode=377, maxMBSortInHeap=6.104498380038031, sim=RandomSimilarity(queryNorm=true,coord=crazy): {}, locale=en-TK, timezone=Etc/GMT-3
[junit4] 2> NOTE: Linux 4.4.0-53-generic amd64/Oracle Corporation 9-ea (64-bit)/cpus=12,threads=1,free=290822048,total=501743616
[junit4] 2> NOTE: All tests run in this JVM: [DirectUpdateHandlerOptimizeTest, TestPerFieldSimilarityClassic, SolrCoreCheckLockOnStartupTest, SolrMetricsIntegrationTest, CdcrRequestHandlerTest, CloneFieldUpdateProcessorFactoryTest, TestXIncludeConfig, TestSubQueryTransformerCrossCore, TestCloudPseudoReturnFields, TestSchemaNameResource, TestSchemaManager, TestMacros, HdfsSyncSliceTest, TestSolrQueryResponse, LeaderFailoverAfterPartitionTest, TestSchemaVersionResource, CleanupOldIndexTest, BlobRepositoryCloudTest, OpenExchangeRatesOrgProviderTest, DataDrivenBlockJoinTest, TestLMJelinekMercerSimilarityFactory, EnumFieldTest, PKIAuthenticationIntegrationTest, TestMaxScoreQueryParser, LukeRequestHandlerTest, TestMiniSolrCloudCluster, TestCloudDeleteByQuery, TestTrieFacet, TestSort, PrimitiveFieldTypeTest, TestShardHandlerFactory, OverseerTaskQueueTest, TestZkChroot, DistributedFacetPivotSmallAdvancedTest, OverseerTest, ChangedSchemaMergeTest, TestSolrCloudWithKerberosAlt, TestConfigSetsAPIZkFailure, HdfsBasicDistributedZk2Test, TestIndexingPerformance, UtilsToolTest, TestRecovery, TestConfigOverlay, TestGraphTermsQParserPlugin, TestReversedWildcardFilterFactory, SolrCoreMetricManagerTest, DistributedQueryComponentCustomSortTest, TestBlendedInfixSuggestions, StatsReloadRaceTest, DistributedQueueTest, TestTrackingShardHandlerFactory, SpatialRPTFieldTypeTest, FieldMutatingUpdateProcessorTest, CoreAdminRequestStatusTest, TestOnReconnectListenerSupport, ResponseHeaderTest, AutoCommitTest, TestNumericTerms32, TestConfigSets, PluginInfoTest, SharedFSAutoReplicaFailoverUtilsTest, UpdateParamsTest, HdfsChaosMonkeySafeLeaderTest, TestDistributedMissingSort, DebugComponentTest, TestHdfsCloudBackupRestore, TlogReplayBufferedWhileIndexingTest, TestImpersonationWithHadoopAuth, TestCustomSort, TestSmileRequest, CdcrBootstrapTest, DOMUtilTest, AssignTest, TestUtils, TestRestoreCore, FullSolrCloudDistribCmdsTest, TestPostingsSolrHighlighter, TestDistributedStatsComponentCardinality, QueryParsingTest, TestCoreDiscovery, MetricUtilsTest, TestDFRSimilarityFactory, TestFieldCacheVsDocValues, TemplateUpdateProcessorTest, TestDynamicLoading, UnloadDistributedZkTest, TestSolrDeletionPolicy1, GraphQueryTest, CurrencyFieldXmlFileTest, TestCollapseQParserPlugin, CoreSorterTest, TestPhraseSuggestions, SolrTestCaseJ4Test, SortSpecParsingTest, RequestLoggingTest, HdfsDirectoryFactoryTest, TestStressLiveNodes, TestCollationField, ShowFileRequestHandlerTest, ResponseLogComponentTest, SaslZkACLProviderTest, SolrCloudExampleTest, TestGeoJSONResponseWriter, HardAutoCommitTest, MetricsHandlerTest, DeleteReplicaTest, TestRuleBasedAuthorizationPlugin, LeaderElectionTest, ZkCLITest, TestFaceting, TestHashPartitioner, TermVectorComponentDistributedTest, TestRealTimeGet, TestReload, TestCoreContainer, SimpleFacetsTest, SolrCoreTest, SpellCheckComponentTest, TestLazyCores, HighlighterTest, DistributedQueryElevationComponentTest, SolrIndexSplitterTest, SimplePostToolTest, AnalysisAfterCoreReloadTest, TestExtendedDismaxParser, CoreAdminHandlerTest, TestFoldingMultitermQuery, SuggesterTest, PolyFieldTest, SchemaVersionSpecificBehaviorTest, QueryEqualityTest, TestRemoteStreaming, DocValuesMultiTest, DistanceFunctionTest, CacheHeaderTest, TestWriterPerf, TermsComponentTest, RequestHandlersTest, TermVectorComponentTest, FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, JSONWriterTest, TestAnalyzedSuggestions, TestPartialUpdateDeduplication, PingRequestHandlerTest, TestLFUCache, TestEmbeddedSolrServerConstructors, TestJettySolrRunner, ActionThrottleTest, AsyncCallRequestStatusResponseTest, CdcrReplicationHandlerTest, CdcrVersionReplicationTest, CollectionsAPIAsyncDistributedZkTest, ConcurrentDeleteAndCreateCollectionTest, ConnectionManagerTest, CreateCollectionCleanupTest, DeleteInactiveReplicaTest, DeleteStatusTest, DistribCursorPagingTest, DocValuesNotIndexedTest, ForceLeaderTest, LeaderInitiatedRecoveryOnCommitTest, PeerSyncReplicationTest, SharedFSAutoReplicaFailoverTest, SimpleCollectionCreateDeleteTest, SolrCLIZkUtilsTest, TestCloudInspectUtil, TestCloudPivotFacet, TestCollectionAPI, TestLeaderElectionZkExpiry, TestLockTree, TestMiniSolrCloudClusterSSL, TestSolrCloudWithSecureImpersonation, TriLevelCompositeIdRoutingTest, TestInfoStreamLogging, TestInitParams, TestNRTOpen, TestSolrConfigHandler, TestConfigReload, TestSQLHandlerNonCloud, TestSolrConfigHandlerCloud, FacetPivotSmallTest, TestExpandComponent, JavabinLoaderTest, TestUnifiedSolrHighlighter, CheckHdfsIndexTest, SolrMetricManagerTest, SolrJmxReporterTest, SmileWriterTest, SmileWriterTest, TestBinaryResponseWriter, TestGraphMLResponseWriter, TestJavabinTupleStreamParser, TestPushWriter, TestRawResponseWriter, TestSubQueryTransformer, TestBulkSchemaAPI, ManagedSchemaRoundRobinCloudTest, TestBulkSchemaConcurrent, TestReloadDeadlock, TestSearcherReuse, TestSolrCoreParser, TestSolrFieldCacheMBean, TestJsonFacetRefinement, TestOrdValues, BJQParserTest, BlockJoinFacetDistribTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BlockJoinFacetDistribTest -Dtests.seed=60F981BE3E6F147D -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en-TK -Dtests.timezone=Etc/GMT-3 -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J2 | 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=25184, name=OverseerHdfsCoreFailoverThread-97278684641558541-127.0.0.1:46671_solr-n_0000000002, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
[junit4] > at java.base/java.lang.Thread.sleep(Native Method)
[junit4] > at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:139)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] > at __randomizedtesting.SeedInfo.seed([60F981BE3E6F147D]:0)
[junit4] Completed [632/680 (1!)] on J2 in 32.11s, 1 test, 1 error <<< FAILURES!
[...truncated 51696 lines...]