Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/6167/
Java: 32bit/jdk1.8.0_102 -server -XX:+UseParallelGC
1 tests failed.
FAILED:
org.apache.solr.cloud.TestTolerantUpdateProcessorCloud.testVariousAddsViaShard1NonLeaderClient
Error Message:
GC overhead limit exceeded
Stack Trace:
java.lang.OutOfMemoryError: GC overhead limit exceeded
at
__randomizedtesting.SeedInfo.seed([A1779DCC8FE98CA2:53B5634571832994]:0)
at java.util.HashMap.newNode(HashMap.java:1742)
at java.util.HashMap.putVal(HashMap.java:630)
at java.util.HashMap.put(HashMap.java:611)
at java.util.HashSet.add(HashSet.java:219)
at
sun.security.util.AlgorithmDecomposer.decompose(AlgorithmDecomposer.java:76)
at
sun.security.ssl.SSLAlgorithmDecomposer.decompose(SSLAlgorithmDecomposer.java:248)
at
sun.security.util.AbstractAlgorithmConstraints.checkAlgorithm(AbstractAlgorithmConstraints.java:104)
at
sun.security.util.DisabledAlgorithmConstraints.permits(DisabledAlgorithmConstraints.java:91)
at
sun.security.ssl.SSLAlgorithmConstraints.permits(SSLAlgorithmConstraints.java:144)
at
sun.security.ssl.SignatureAndHashAlgorithm.getSupportedAlgorithms(SignatureAndHashAlgorithm.java:158)
at
sun.security.ssl.Handshaker.getLocalSupportedSignAlgs(Handshaker.java:442)
at
sun.security.ssl.ClientHandshaker.getKickstartMessage(ClientHandshaker.java:1392)
at sun.security.ssl.Handshaker.kickstart(Handshaker.java:1014)
at
sun.security.ssl.SSLSocketImpl.kickstartHandshake(SSLSocketImpl.java:1487)
at
sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1351)
at
sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1403)
at
sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1387)
at
org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:394)
at
org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:353)
at
org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:134)
at
org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:353)
at
org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:380)
at
org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)
at
org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88)
at
org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
at
org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
at
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
at
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
at
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:511)
at
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:259)
at
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:248)
Build Log:
[...truncated 10819 lines...]
[junit4] Suite: org.apache.solr.cloud.TestTolerantUpdateProcessorCloud
[junit4] 2> Creating dataDir:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\init-core-data-001
[junit4] 2> 343800 INFO
(SUITE-TestTolerantUpdateProcessorCloud-seed#[A1779DCC8FE98CA2]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via:
@org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 343803 INFO
(SUITE-TestTolerantUpdateProcessorCloud-seed#[A1779DCC8FE98CA2]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 5 servers in
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\tempDir-001
[junit4] 2> 343803 INFO
(SUITE-TestTolerantUpdateProcessorCloud-seed#[A1779DCC8FE98CA2]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 343804 INFO (Thread-786) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 343804 INFO (Thread-786) [ ] o.a.s.c.ZkTestServer Starting
server
[junit4] 2> 343905 INFO
(SUITE-TestTolerantUpdateProcessorCloud-seed#[A1779DCC8FE98CA2]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:61825
[junit4] 2> 343917 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 0x157a59850910000, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 343921 INFO (jetty-launcher-880-thread-1) [ ]
o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 343921 INFO (jetty-launcher-880-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@ff4f3a{/solr,null,AVAILABLE}
[junit4] 2> 343924 INFO (jetty-launcher-880-thread-5) [ ]
o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 343925 INFO (jetty-launcher-880-thread-5) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@2e0cc3{/solr,null,AVAILABLE}
[junit4] 2> 343926 INFO (jetty-launcher-880-thread-2) [ ]
o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 343927 INFO (jetty-launcher-880-thread-2) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@d43230{/solr,null,AVAILABLE}
[junit4] 2> 343928 INFO (jetty-launcher-880-thread-5) [ ]
o.e.j.s.ServerConnector Started ServerConnector@153c3ee{SSL,[ssl,
http/1.1]}{127.0.0.1:61830}
[junit4] 2> 343928 INFO (jetty-launcher-880-thread-5) [ ]
o.e.j.s.Server Started @348714ms
[junit4] 2> 343928 INFO (jetty-launcher-880-thread-5) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=61830}
[junit4] 2> 343928 INFO (jetty-launcher-880-thread-5) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.0.0
[junit4] 2> 343928 INFO (jetty-launcher-880-thread-5) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 343928 INFO (jetty-launcher-880-thread-5) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 343928 INFO (jetty-launcher-880-thread-5) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2016-10-08T18:40:05.384Z
[junit4] 2> 343929 INFO (jetty-launcher-880-thread-2) [ ]
o.e.j.s.ServerConnector Started ServerConnector@4abf96{SSL,[ssl,
http/1.1]}{127.0.0.1:61833}
[junit4] 2> 343929 INFO (jetty-launcher-880-thread-2) [ ]
o.e.j.s.Server Started @348715ms
[junit4] 2> 343929 INFO (jetty-launcher-880-thread-2) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=61833}
[junit4] 2> 343929 INFO (jetty-launcher-880-thread-2) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.0.0
[junit4] 2> 343929 INFO (jetty-launcher-880-thread-2) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 343929 INFO (jetty-launcher-880-thread-2) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 343929 INFO (jetty-launcher-880-thread-2) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2016-10-08T18:40:05.385Z
[junit4] 2> 343931 INFO (jetty-launcher-880-thread-1) [ ]
o.e.j.s.ServerConnector Started ServerConnector@c60d2c{SSL,[ssl,
http/1.1]}{127.0.0.1:61829}
[junit4] 2> 343931 INFO (jetty-launcher-880-thread-1) [ ]
o.e.j.s.Server Started @348718ms
[junit4] 2> 343931 INFO (jetty-launcher-880-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=61829}
[junit4] 2> 343931 INFO (jetty-launcher-880-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.0.0
[junit4] 2> 343931 INFO (jetty-launcher-880-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 343931 INFO (jetty-launcher-880-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 343931 INFO (jetty-launcher-880-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2016-10-08T18:40:05.387Z
[junit4] 2> 343936 INFO (jetty-launcher-880-thread-4) [ ]
o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 343936 INFO (jetty-launcher-880-thread-3) [ ]
o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 343938 INFO (jetty-launcher-880-thread-4) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@58265d{/solr,null,AVAILABLE}
[junit4] 2> 343938 INFO (jetty-launcher-880-thread-3) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@67f866{/solr,null,AVAILABLE}
[junit4] 2> 343941 INFO (jetty-launcher-880-thread-4) [ ]
o.e.j.s.ServerConnector Started ServerConnector@a24a7c{SSL,[ssl,
http/1.1]}{127.0.0.1:61844}
[junit4] 2> 343941 INFO (jetty-launcher-880-thread-4) [ ]
o.e.j.s.Server Started @348728ms
[junit4] 2> 343941 INFO (jetty-launcher-880-thread-4) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=61844}
[junit4] 2> 343941 INFO (jetty-launcher-880-thread-3) [ ]
o.e.j.s.ServerConnector Started ServerConnector@12b8c6c{SSL,[ssl,
http/1.1]}{127.0.0.1:61845}
[junit4] 2> 343942 INFO (jetty-launcher-880-thread-3) [ ]
o.e.j.s.Server Started @348728ms
[junit4] 2> 343942 INFO (jetty-launcher-880-thread-3) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=61845}
[junit4] 2> 343942 INFO (jetty-launcher-880-thread-4) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.0.0
[junit4] 2> 343942 INFO (jetty-launcher-880-thread-4) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 343942 INFO (jetty-launcher-880-thread-4) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 343942 INFO (jetty-launcher-880-thread-3) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.0.0
[junit4] 2> 343942 INFO (jetty-launcher-880-thread-4) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2016-10-08T18:40:05.398Z
[junit4] 2> 343942 INFO (jetty-launcher-880-thread-3) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 343942 INFO (jetty-launcher-880-thread-3) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 343942 INFO (jetty-launcher-880-thread-3) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2016-10-08T18:40:05.398Z
[junit4] 2> 343954 INFO (jetty-launcher-880-thread-5) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 343955 INFO (jetty-launcher-880-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 343960 INFO (jetty-launcher-880-thread-2) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 343961 INFO (jetty-launcher-880-thread-3) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 343974 INFO (jetty-launcher-880-thread-4) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 343975 INFO (jetty-launcher-880-thread-3) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:61825/solr
[junit4] 2> 343976 INFO (jetty-launcher-880-thread-2) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:61825/solr
[junit4] 2> 343978 INFO (jetty-launcher-880-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:61825/solr
[junit4] 2> 343984 INFO (jetty-launcher-880-thread-4) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:61825/solr
[junit4] 2> 344007 INFO (jetty-launcher-880-thread-5) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:61825/solr
[junit4] 2> 344016 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 0x157a59850910006, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 344023 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 0x157a5985091000a, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 344082 INFO (jetty-launcher-880-thread-4)
[n:127.0.0.1:61844_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:61844_solr
[junit4] 2> 344085 INFO (jetty-launcher-880-thread-4)
[n:127.0.0.1:61844_solr ] o.a.s.c.Overseer Overseer
(id=96727990617047053-127.0.0.1:61844_solr-n_0000000000) starting
[junit4] 2> 344085 INFO (jetty-launcher-880-thread-3)
[n:127.0.0.1:61845_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:61845_solr
[junit4] 2> 344086 INFO (jetty-launcher-880-thread-1)
[n:127.0.0.1:61829_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:61829_solr
[junit4] 2> 344086 INFO (jetty-launcher-880-thread-5)
[n:127.0.0.1:61830_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:61830_solr
[junit4] 2> 344086 INFO (jetty-launcher-880-thread-2)
[n:127.0.0.1:61833_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:61833_solr
[junit4] 2> 344090 INFO
(zkCallback-902-thread-1-processing-n:127.0.0.1:61829_solr)
[n:127.0.0.1:61829_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (4)
[junit4] 2> 344106 INFO
(zkCallback-905-thread-1-processing-n:127.0.0.1:61845_solr)
[n:127.0.0.1:61845_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (4)
[junit4] 2> 344108 INFO (jetty-launcher-880-thread-5)
[n:127.0.0.1:61830_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\tempDir-001\node3\.
[junit4] 2> 344113 INFO
(zkCallback-904-thread-1-processing-n:127.0.0.1:61844_solr)
[n:127.0.0.1:61844_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (4)
[junit4] 2> 344114 INFO
(zkCallback-903-thread-1-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (4)
[junit4] 2> 344114 INFO
(zkCallback-906-thread-1-processing-n:127.0.0.1:61830_solr)
[n:127.0.0.1:61830_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (4)
[junit4] 2> 344127 INFO (jetty-launcher-880-thread-2)
[n:127.0.0.1:61833_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\tempDir-001\node2\.
[junit4] 2> 344129 INFO (jetty-launcher-880-thread-3)
[n:127.0.0.1:61845_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\tempDir-001\node5\.
[junit4] 2> 344129 INFO (jetty-launcher-880-thread-1)
[n:127.0.0.1:61829_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\tempDir-001\node1\.
[junit4] 2> 344137 INFO (jetty-launcher-880-thread-4)
[n:127.0.0.1:61844_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:61844_solr
[junit4] 2> 344140 INFO
(zkCallback-902-thread-1-processing-n:127.0.0.1:61829_solr)
[n:127.0.0.1:61829_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (5)
[junit4] 2> 344140 INFO
(zkCallback-904-thread-1-processing-n:127.0.0.1:61844_solr)
[n:127.0.0.1:61844_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (5)
[junit4] 2> 344140 INFO
(zkCallback-906-thread-1-processing-n:127.0.0.1:61830_solr)
[n:127.0.0.1:61830_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (5)
[junit4] 2> 344142 INFO
(zkCallback-903-thread-1-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (5)
[junit4] 2> 344142 INFO
(zkCallback-905-thread-1-processing-n:127.0.0.1:61845_solr)
[n:127.0.0.1:61845_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (5)
[junit4] 2> 344155 INFO (jetty-launcher-880-thread-4)
[n:127.0.0.1:61844_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\tempDir-001\node4\.
[junit4] 2> 344160 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 0x157a59850910010, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 344164 INFO
(SUITE-TestTolerantUpdateProcessorCloud-seed#[A1779DCC8FE98CA2]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5)
[junit4] 2> 345024 INFO (qtp555947-4031) [n:127.0.0.1:61844_solr ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params
replicationFactor=2&property.schema=schema15.xml&property.config=solrconfig-distrib-update-processor-chains.xml&collection.configName=solrCloudCollectionConfig&name=test_col&action=CREATE&numShards=2&wt=javabin&version=2
and sendToOCPQueue=true
[junit4] 2> 345032 INFO
(OverseerThreadFactory-1909-thread-1-processing-n:127.0.0.1:61844_solr)
[n:127.0.0.1:61844_solr ] o.a.s.c.CreateCollectionCmd Create collection
test_col
[junit4] 2> 345166 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr ]
o.a.s.h.a.CoreAdminOperation core create command
property.schema=schema15.xml&property.config=solrconfig-distrib-update-processor-chains.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=test_col_shard1_replica1&action=CREATE&numShards=2&collection=test_col&shard=shard1&wt=javabin&version=2
[junit4] 2> 345264 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr ]
o.a.s.h.a.CoreAdminOperation core create command
property.schema=schema15.xml&property.config=solrconfig-distrib-update-processor-chains.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=test_col_shard1_replica2&action=CREATE&numShards=2&collection=test_col&shard=shard1&wt=javabin&version=2
[junit4] 2> 345274 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr ]
o.a.s.h.a.CoreAdminOperation core create command
property.schema=schema15.xml&property.config=solrconfig-distrib-update-processor-chains.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=test_col_shard2_replica1&action=CREATE&numShards=2&collection=test_col&shard=shard2&wt=javabin&version=2
[junit4] 2> 345330 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr ]
o.a.s.h.a.CoreAdminOperation core create command
property.schema=schema15.xml&property.config=solrconfig-distrib-update-processor-chains.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=test_col_shard2_replica2&action=CREATE&numShards=2&collection=test_col&shard=shard2&wt=javabin&version=2
[junit4] 2> 345440 INFO
(zkCallback-902-thread-1-processing-n:127.0.0.1:61829_solr)
[n:127.0.0.1:61829_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 345440 INFO
(zkCallback-904-thread-3-processing-n:127.0.0.1:61844_solr)
[n:127.0.0.1:61844_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 345442 INFO
(zkCallback-903-thread-1-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 345442 INFO
(zkCallback-906-thread-1-processing-n:127.0.0.1:61830_solr)
[n:127.0.0.1:61830_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 346309 WARN (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 x:test_col_shard1_replica1] o.a.s.c.Config Beginning with
Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 346312 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 x:test_col_shard1_replica1] o.a.s.c.SolrConfig Using
Lucene MatchVersion: 7.0.0
[junit4] 2> 346314 WARN (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 x:test_col_shard1_replica2] o.a.s.c.Config Beginning with
Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 346314 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 x:test_col_shard1_replica2] o.a.s.c.SolrConfig Using
Lucene MatchVersion: 7.0.0
[junit4] 2> 346318 WARN (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 x:test_col_shard2_replica1] o.a.s.c.Config Beginning with
Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 346319 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 x:test_col_shard2_replica1] o.a.s.c.SolrConfig Using
Lucene MatchVersion: 7.0.0
[junit4] 2> 346320 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 x:test_col_shard1_replica1]
o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but
managed schema resource managed-schema not found - loading non-managed schema
schema15.xml instead
[junit4] 2> 346321 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 x:test_col_shard1_replica2]
o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but
managed schema resource managed-schema not found - loading non-managed schema
schema15.xml instead
[junit4] 2> 346328 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 x:test_col_shard1_replica1] o.a.s.s.IndexSchema
[test_col_shard1_replica1] Schema name=test
[junit4] 2> 346329 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 x:test_col_shard1_replica2] o.a.s.s.IndexSchema
[test_col_shard1_replica2] Schema name=test
[junit4] 2> 346376 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 x:test_col_shard2_replica1]
o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but
managed schema resource managed-schema not found - loading non-managed schema
schema15.xml instead
[junit4] 2> 346395 WARN (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 x:test_col_shard1_replica2] o.a.s.s.IndexSchema
[test_col_shard1_replica2] default search field in schema is text. WARNING:
Deprecated, please use 'df' on request instead.
[junit4] 2> 346395 WARN (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 x:test_col_shard1_replica1] o.a.s.s.IndexSchema
[test_col_shard1_replica1] default search field in schema is text. WARNING:
Deprecated, please use 'df' on request instead.
[junit4] 2> 346402 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 x:test_col_shard2_replica1] o.a.s.s.IndexSchema
[test_col_shard2_replica1] Schema name=test
[junit4] 2> 346415 WARN (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 x:test_col_shard2_replica2] o.a.s.c.Config Beginning with
Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 346415 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 x:test_col_shard2_replica2] o.a.s.c.SolrConfig Using
Lucene MatchVersion: 7.0.0
[junit4] 2> 346429 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 x:test_col_shard2_replica2]
o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but
managed schema resource managed-schema not found - loading non-managed schema
schema15.xml instead
[junit4] 2> 346436 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 x:test_col_shard2_replica2] o.a.s.s.IndexSchema
[test_col_shard2_replica2] Schema name=test
[junit4] 2> 346463 WARN (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 x:test_col_shard2_replica1] o.a.s.s.IndexSchema
[test_col_shard2_replica1] default search field in schema is text. WARNING:
Deprecated, please use 'df' on request instead.
[junit4] 2> 346464 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 x:test_col_shard1_replica1] o.a.s.s.IndexSchema Loaded
schema test/1.6 with uniqueid field id
[junit4] 2> 346465 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 x:test_col_shard1_replica2] o.a.s.s.IndexSchema Loaded
schema test/1.6 with uniqueid field id
[junit4] 2> 346499 WARN (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 x:test_col_shard2_replica2] o.a.s.s.IndexSchema
[test_col_shard2_replica2] default search field in schema is text. WARNING:
Deprecated, please use 'df' on request instead.
[junit4] 2> 346502 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 x:test_col_shard2_replica1] o.a.s.s.IndexSchema Loaded
schema test/1.6 with uniqueid field id
[junit4] 2> 346507 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 x:test_col_shard1_replica1] o.a.s.s.ManagedIndexSchema
Created and persisted managed schema znode at
/configs/solrCloudCollectionConfig/managed-schema
[junit4] 2> 346507 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 x:test_col_shard1_replica2] o.a.s.s.ManagedIndexSchema
Managed schema znode at /configs/solrCloudCollectionConfig/managed-schema
already exists - no need to create it
[junit4] 2> 346516 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 x:test_col_shard1_replica2]
o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in
ZooKeeper, renamed the non-managed schema
/configs/solrCloudCollectionConfig/schema15.xml to
/configs/solrCloudCollectionConfig/schema15.xml.bak
[junit4] 2> 346516 WARN (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 x:test_col_shard1_replica1]
o.a.s.s.ManagedIndexSchemaFactory Error persisting managed schema resource
managed-schema
[junit4] 2> org.apache.zookeeper.KeeperException$NoNodeException:
KeeperErrorCode = NoNode for /configs/solrCloudCollectionConfig/schema15.xml
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:245)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:242)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:242)
[junit4] 2> at
org.apache.solr.schema.ManagedIndexSchemaFactory.zkUgradeToManagedSchema(ManagedIndexSchemaFactory.java:349)
[junit4] 2> at
org.apache.solr.schema.ManagedIndexSchemaFactory.upgradeToManagedSchema(ManagedIndexSchemaFactory.java:268)
[junit4] 2> at
org.apache.solr.schema.ManagedIndexSchemaFactory.create(ManagedIndexSchemaFactory.java:186)
[junit4] 2> at
org.apache.solr.schema.ManagedIndexSchemaFactory.create(ManagedIndexSchemaFactory.java:45)
[junit4] 2> at
org.apache.solr.schema.IndexSchemaFactory.buildIndexSchema(IndexSchemaFactory.java:75)
[junit4] 2> at
org.apache.solr.core.ConfigSetService.createIndexSchema(ConfigSetService.java:107)
[junit4] 2> at
org.apache.solr.core.ConfigSetService.getConfig(ConfigSetService.java:78)
[junit4] 2> at
org.apache.solr.core.CoreContainer.create(CoreContainer.java:862)
[junit4] 2> at
org.apache.solr.core.CoreContainer.create(CoreContainer.java:801)
[junit4] 2> at
org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:85)
[junit4] 2> at
org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:374)
[junit4] 2> at
org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:365)
[junit4] 2> at
org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:156)
[junit4] 2> at
org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:153)
[junit4] 2> at
org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:659)
[junit4] 2> at
org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:441)
[junit4] 2> at
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:302)
[junit4] 2> at
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:253)
[junit4] 2> at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1676)
[junit4] 2> at
org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:111)
[junit4] 2> at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1676)
[junit4] 2> at
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:581)
[junit4] 2> at
org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
[junit4] 2> at
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1160)
[junit4] 2> at
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511)
[junit4] 2> at
org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[junit4] 2> at
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1092)
[junit4] 2> at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at
org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:399)
[junit4] 2> at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
[junit4] 2> at
org.eclipse.jetty.server.Server.handle(Server.java:518)
[junit4] 2> at
org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:308)
[junit4] 2> at
org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:244)
[junit4] 2> at
org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
[junit4] 2> at
org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
[junit4] 2> at
org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:186)
[junit4] 2> at
org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
[junit4] 2> at
org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
[junit4] 2> at
org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceAndRun(ExecuteProduceConsume.java:246)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:156)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:654)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 346520 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 x:test_col_shard1_replica2] o.a.s.c.CoreContainer Creating
SolrCore 'test_col_shard1_replica2' using configuration from collection test_col
[junit4] 2> 346520 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 x:test_col_shard1_replica1] o.a.s.c.CoreContainer Creating
SolrCore 'test_col_shard1_replica1' using configuration from collection test_col
[junit4] 2> 346521 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1] o.a.s.c.SolrCore
[[test_col_shard1_replica1] ] Opening new SolrCore at
[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\tempDir-001\node4\test_col_shard1_replica1],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\tempDir-001\node4\.\test_col_shard1_replica1\data\]
[junit4] 2> 346521 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2] o.a.s.c.SolrCore
[[test_col_shard1_replica2] ] Opening new SolrCore at
[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\tempDir-001\node2\test_col_shard1_replica2],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\tempDir-001\node2\.\test_col_shard1_replica2\data\]
[junit4] 2> 346521 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1]
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be45a5
[junit4] 2> 346521 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be45a5
[junit4] 2> 346524 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy:
minMergeSize=0, mergeFactor=10, maxMergeSize=158345057,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.1]
[junit4] 2> 346524 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy:
minMergeSize=0, mergeFactor=10, maxMergeSize=158345057,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.1]
[junit4] 2> 346530 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 x:test_col_shard2_replica2] o.a.s.s.IndexSchema Loaded
schema test/1.6 with uniqueid field id
[junit4] 2> 346536 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 x:test_col_shard2_replica1] o.a.s.s.ManagedIndexSchema
Managed schema znode at /configs/solrCloudCollectionConfig/managed-schema
already exists - no need to create it
[junit4] 2> 346536 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 x:test_col_shard2_replica1]
o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in
ZooKeeper, the non-managed schema
/configs/solrCloudCollectionConfig/schema15.xml no longer exists.
[junit4] 2> 346537 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 x:test_col_shard2_replica1] o.a.s.c.CoreContainer Creating
SolrCore 'test_col_shard2_replica1' using configuration from collection test_col
[junit4] 2> 346537 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1] o.a.s.c.SolrCore
[[test_col_shard2_replica1] ] Opening new SolrCore at
[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\tempDir-001\node3\test_col_shard2_replica1],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\tempDir-001\node3\.\test_col_shard2_replica1\data\]
[junit4] 2> 346537 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1]
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be45a5
[junit4] 2> 346539 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy:
minMergeSize=0, mergeFactor=10, maxMergeSize=158345057,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.1]
[junit4] 2> 346551 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 x:test_col_shard2_replica2] o.a.s.s.ManagedIndexSchema
Managed schema znode at /configs/solrCloudCollectionConfig/managed-schema
already exists - no need to create it
[junit4] 2> 346551 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 x:test_col_shard2_replica2]
o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in
ZooKeeper, the non-managed schema
/configs/solrCloudCollectionConfig/schema15.xml no longer exists.
[junit4] 2> 346552 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 x:test_col_shard2_replica2] o.a.s.c.CoreContainer Creating
SolrCore 'test_col_shard2_replica2' using configuration from collection test_col
[junit4] 2> 346552 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2] o.a.s.c.SolrCore
[[test_col_shard2_replica2] ] Opening new SolrCore at
[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\tempDir-001\node1\test_col_shard2_replica2],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001\tempDir-001\node1\.\test_col_shard2_replica2\data\]
[junit4] 2> 346552 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be45a5
[junit4] 2> 346556 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy:
minMergeSize=0, mergeFactor=10, maxMergeSize=158345057,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.1]
[junit4] 2> 346563 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 346563 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 346565 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 346565 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 346566 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=15, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=69.21484375,
floorSegmentMB=1.158203125, forceMergeDeletesPctAllowed=19.007950752293773,
segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 346566 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 346566 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 346568 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 346568 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 346568 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=15, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=69.21484375,
floorSegmentMB=1.158203125, forceMergeDeletesPctAllowed=19.007950752293773,
segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 346579 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 346579 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 346581 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 346581 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 346583 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 346583 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 346583 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=15, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=69.21484375,
floorSegmentMB=1.158203125, forceMergeDeletesPctAllowed=19.007950752293773,
segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 346585 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 346585 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 346586 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=15, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=69.21484375,
floorSegmentMB=1.158203125, forceMergeDeletesPctAllowed=19.007950752293773,
segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 346588 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@101256c[test_col_shard1_replica1]
main]
[junit4] 2> 346588 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.s.SolrIndexSearcher Opening [Searcher@ad3444[test_col_shard1_replica2]
main]
[junit4] 2> 346589 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/solrCloudCollectionConfig
[junit4] 2> 346589 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/solrCloudCollectionConfig
[junit4] 2> 346590 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 346590 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 346590 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at
/configs/solrCloudCollectionConfig/managed-schema
[junit4] 2> 346590 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1]
o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at
/configs/solrCloudCollectionConfig/managed-schema
[junit4] 2> 346591 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.s.SolrIndexSearcher Opening [Searcher@16ea1b7[test_col_shard2_replica2]
main]
[junit4] 2> 346592 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@533549[test_col_shard2_replica1]
main]
[junit4] 2> 346593 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/solrCloudCollectionConfig
[junit4] 2> 346593 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/solrCloudCollectionConfig
[junit4] 2> 346593 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 346594 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at
/configs/solrCloudCollectionConfig/managed-schema
[junit4] 2> 346594 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 346594 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1]
o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at
/configs/solrCloudCollectionConfig/managed-schema
[junit4] 2> 346595 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2] o.a.s.u.UpdateLog
Could not find max version in index or recent updates, using new clock
1547647852794085376
[junit4] 2> 346595 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1] o.a.s.u.UpdateLog
Could not find max version in index or recent updates, using new clock
1547647852794085376
[junit4] 2> 346596 INFO
(searcherExecutor-1912-thread-1-processing-n:127.0.0.1:61833_solr
x:test_col_shard1_replica2 s:shard1 c:test_col r:core_node2)
[n:127.0.0.1:61833_solr c:test_col s:shard1 r:core_node2
x:test_col_shard1_replica2] o.a.s.c.SolrCore [test_col_shard1_replica2]
Registered new searcher Searcher@ad3444[test_col_shard1_replica2]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 346596 INFO
(searcherExecutor-1913-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.c.SolrCore [test_col_shard1_replica1]
Registered new searcher Searcher@101256c[test_col_shard1_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 346599 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2] o.a.s.u.UpdateLog
Could not find max version in index or recent updates, using new clock
1547647852798279680
[junit4] 2> 346599 INFO
(searcherExecutor-1915-thread-1-processing-n:127.0.0.1:61829_solr
x:test_col_shard2_replica2 s:shard2 c:test_col r:core_node4)
[n:127.0.0.1:61829_solr c:test_col s:shard2 r:core_node4
x:test_col_shard2_replica2] o.a.s.c.SolrCore [test_col_shard2_replica2]
Registered new searcher Searcher@16ea1b7[test_col_shard2_replica2]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 346610 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for
shard shard2: total=2 found=1 timeoutin=9999ms
[junit4] 2> 346610 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 346610 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 346610 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.c.SyncStrategy Sync replicas to
https://127.0.0.1:61833/solr/test_col_shard1_replica2/
[junit4] 2> 346610 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2] o.a.s.u.PeerSync
PeerSync: core=test_col_shard1_replica2 url=https://127.0.0.1:61833/solr START
replicas=[https://127.0.0.1:61844/solr/test_col_shard1_replica1/] nUpdates=100
[junit4] 2> 346610 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2] o.a.s.u.PeerSync
PeerSync: core=test_col_shard1_replica2 url=https://127.0.0.1:61833/solr DONE.
We have no versions. sync failed.
[junit4] 2> 346611 INFO
(searcherExecutor-1914-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.c.SolrCore [test_col_shard2_replica1]
Registered new searcher Searcher@533549[test_col_shard2_replica1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 346611 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1] o.a.s.u.UpdateLog
Could not find max version in index or recent updates, using new clock
1547647852810862592
[junit4] 2> 346630 INFO (qtp555947-4036) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1] o.a.s.c.S.Request
[test_col_shard1_replica1] webapp=/solr path=/get
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
status=0 QTime=3
[junit4] 2> 346631 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the
next candidate
[junit4] 2> 346631 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we
can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 346642 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
https://127.0.0.1:61833/solr/test_col_shard1_replica2/ shard1
[junit4] 2> 346747 INFO
(zkCallback-902-thread-1-processing-n:127.0.0.1:61829_solr)
[n:127.0.0.1:61829_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 346747 INFO
(zkCallback-904-thread-3-processing-n:127.0.0.1:61844_solr)
[n:127.0.0.1:61844_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 346747 INFO
(zkCallback-906-thread-1-processing-n:127.0.0.1:61830_solr)
[n:127.0.0.1:61830_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 346747 INFO
(zkCallback-903-thread-1-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 346794 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 346799 INFO (qtp26371412-4016) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores
params={property.schema=schema15.xml&property.config=solrconfig-distrib-update-processor-chains.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=test_col_shard1_replica2&action=CREATE&numShards=2&collection=test_col&shard=shard1&wt=javabin&version=2}
status=0 QTime=1534
[junit4] 2> 346899 INFO
(zkCallback-902-thread-1-processing-n:127.0.0.1:61829_solr)
[n:127.0.0.1:61829_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 346899 INFO
(zkCallback-904-thread-1-processing-n:127.0.0.1:61844_solr)
[n:127.0.0.1:61844_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 346899 INFO
(zkCallback-906-thread-1-processing-n:127.0.0.1:61830_solr)
[n:127.0.0.1:61830_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 346899 INFO
(zkCallback-903-thread-1-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 347111 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 347111 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 347111 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.c.SyncStrategy Sync replicas to
https://127.0.0.1:61829/solr/test_col_shard2_replica2/
[junit4] 2> 347111 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2] o.a.s.u.PeerSync
PeerSync: core=test_col_shard2_replica2 url=https://127.0.0.1:61829/solr START
replicas=[https://127.0.0.1:61830/solr/test_col_shard2_replica1/] nUpdates=100
[junit4] 2> 347112 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2] o.a.s.u.PeerSync
PeerSync: core=test_col_shard2_replica2 url=https://127.0.0.1:61829/solr DONE.
We have no versions. sync failed.
[junit4] 2> 347123 INFO (qtp8849263-4060) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1] o.a.s.c.S.Request
[test_col_shard2_replica1] webapp=/solr path=/get
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 347123 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the
next candidate
[junit4] 2> 347123 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we
can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 347126 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
https://127.0.0.1:61829/solr/test_col_shard2_replica2/ shard2
[junit4] 2> 347233 INFO
(zkCallback-902-thread-1-processing-n:127.0.0.1:61829_solr)
[n:127.0.0.1:61829_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 347233 INFO
(zkCallback-904-thread-3-processing-n:127.0.0.1:61844_solr)
[n:127.0.0.1:61844_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 347233 INFO
(zkCallback-906-thread-1-processing-n:127.0.0.1:61830_solr)
[n:127.0.0.1:61830_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 347233 INFO
(zkCallback-903-thread-1-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 347279 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 347284 INFO (qtp379183-4001) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores
params={property.schema=schema15.xml&property.config=solrconfig-distrib-update-processor-chains.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=test_col_shard2_replica2&action=CREATE&numShards=2&collection=test_col&shard=shard2&wt=javabin&version=2}
status=0 QTime=1954
[junit4] 2> 347385 INFO
(zkCallback-902-thread-1-processing-n:127.0.0.1:61829_solr)
[n:127.0.0.1:61829_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 347386 INFO
(zkCallback-904-thread-1-processing-n:127.0.0.1:61844_solr)
[n:127.0.0.1:61844_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 347386 INFO
(zkCallback-903-thread-1-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 347386 INFO
(zkCallback-906-thread-1-processing-n:127.0.0.1:61830_solr)
[n:127.0.0.1:61830_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 347610 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1]
o.a.s.c.ZkController Core needs to recover:test_col_shard1_replica1
[junit4] 2> 347611 INFO
(updateExecutor-896-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 347611 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.c.RecoveryStrategy Starting recovery process.
recoveringAfterStartup=true
[junit4] 2> 347611 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 347611 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.c.RecoveryStrategy Begin buffering updates.
core=[test_col_shard1_replica1]
[junit4] 2> 347611 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.u.UpdateLog Starting to buffer updates.
FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 347611 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.c.RecoveryStrategy Publishing state of core
[test_col_shard1_replica1] as recovering, leader is
[https://127.0.0.1:61833/solr/test_col_shard1_replica2/] and I am
[https://127.0.0.1:61844/solr/test_col_shard1_replica1/]
[junit4] 2> 347614 INFO (qtp555947-4050) [n:127.0.0.1:61844_solr
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores
params={property.schema=schema15.xml&property.config=solrconfig-distrib-update-processor-chains.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=test_col_shard1_replica1&action=CREATE&numShards=2&collection=test_col&shard=shard1&wt=javabin&version=2}
status=0 QTime=2448
[junit4] 2> 347619 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.c.RecoveryStrategy Sending prep recovery
command to [https://127.0.0.1:61833/solr]; [WaitForState:
action=PREPRECOVERY&core=test_col_shard1_replica2&nodeName=127.0.0.1:61844_solr&coreNodeName=core_node1&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 347628 INFO (qtp26371412-4056) [n:127.0.0.1:61833_solr ]
o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node1, state:
recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 347628 INFO (qtp26371412-4056) [n:127.0.0.1:61833_solr ]
o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see
test_col_shard1_replica2 (shard1 of test_col) have state: recovering
[junit4] 2> 347628 INFO (qtp26371412-4056) [n:127.0.0.1:61833_solr ]
o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=test_col,
shard=shard1, thisCore=test_col_shard1_replica2,
leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true,
currentState=down, localState=active, nodeName=127.0.0.1:61844_solr,
coreNodeName=core_node1, onlyIfActiveCheckResult=false, nodeProps:
core_node1:{"core":"test_col_shard1_replica1","base_url":"https://127.0.0.1:61844/solr","node_name":"127.0.0.1:61844_solr","state":"down"}
[junit4] 2> 347639 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1]
o.a.s.c.ZkController Core needs to recover:test_col_shard2_replica1
[junit4] 2> 347640 INFO
(updateExecutor-898-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 347641 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.c.RecoveryStrategy Starting recovery process.
recoveringAfterStartup=true
[junit4] 2> 347641 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 347641 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.c.RecoveryStrategy Begin buffering updates.
core=[test_col_shard2_replica1]
[junit4] 2> 347641 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.u.UpdateLog Starting to buffer updates.
FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 347641 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.c.RecoveryStrategy Publishing state of core
[test_col_shard2_replica1] as recovering, leader is
[https://127.0.0.1:61829/solr/test_col_shard2_replica2/] and I am
[https://127.0.0.1:61830/solr/test_col_shard2_replica1/]
[junit4] 2> 347644 INFO (qtp8849263-4007) [n:127.0.0.1:61830_solr
c:test_col s:shard2 r:core_node3 x:test_col_shard2_replica1]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores
params={property.schema=schema15.xml&property.config=solrconfig-distrib-update-processor-chains.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=test_col_shard2_replica1&action=CREATE&numShards=2&collection=test_col&shard=shard2&wt=javabin&version=2}
status=0 QTime=2370
[junit4] 2> 347644 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.c.RecoveryStrategy Sending prep recovery
command to [https://127.0.0.1:61829/solr]; [WaitForState:
action=PREPRECOVERY&core=test_col_shard2_replica2&nodeName=127.0.0.1:61830_solr&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 347656 INFO (qtp379183-3999) [n:127.0.0.1:61829_solr ]
o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node3, state:
recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 347657 INFO (qtp379183-3999) [n:127.0.0.1:61829_solr ]
o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see
test_col_shard2_replica2 (shard2 of test_col) have state: recovering
[junit4] 2> 347657 INFO (qtp379183-3999) [n:127.0.0.1:61829_solr ]
o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=test_col,
shard=shard2, thisCore=test_col_shard2_replica2,
leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true,
currentState=down, localState=active, nodeName=127.0.0.1:61830_solr,
coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps:
core_node3:{"core":"test_col_shard2_replica1","base_url":"https://127.0.0.1:61830/solr","node_name":"127.0.0.1:61830_solr","state":"down"}
[junit4] 2> 347660 INFO (qtp555947-4031) [n:127.0.0.1:61844_solr ]
o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most
30 seconds. Check all shard replicas
[junit4] 2> 347755 INFO
(zkCallback-902-thread-1-processing-n:127.0.0.1:61829_solr)
[n:127.0.0.1:61829_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 347755 INFO
(zkCallback-904-thread-1-processing-n:127.0.0.1:61844_solr)
[n:127.0.0.1:61844_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 347755 INFO
(zkCallback-903-thread-1-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 347755 INFO
(zkCallback-906-thread-1-processing-n:127.0.0.1:61830_solr)
[n:127.0.0.1:61830_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 348628 INFO (qtp26371412-4056) [n:127.0.0.1:61833_solr ]
o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=test_col,
shard=shard1, thisCore=test_col_shard1_replica2,
leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true,
currentState=recovering, localState=active, nodeName=127.0.0.1:61844_solr,
coreNodeName=core_node1, onlyIfActiveCheckResult=false, nodeProps:
core_node1:{"core":"test_col_shard1_replica1","base_url":"https://127.0.0.1:61844/solr","node_name":"127.0.0.1:61844_solr","state":"recovering"}
[junit4] 2> 348628 INFO (qtp26371412-4056) [n:127.0.0.1:61833_solr ]
o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node1, state: recovering,
checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 348628 INFO (qtp26371412-4056) [n:127.0.0.1:61833_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores
params={nodeName=127.0.0.1:61844_solr&onlyIfLeaderActive=true&core=test_col_shard1_replica2&coreNodeName=core_node1&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2}
status=0 QTime=1001
[junit4] 2> 348658 INFO (qtp379183-3999) [n:127.0.0.1:61829_solr ]
o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=test_col,
shard=shard2, thisCore=test_col_shard2_replica2,
leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true,
currentState=recovering, localState=active, nodeName=127.0.0.1:61830_solr,
coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps:
core_node3:{"core":"test_col_shard2_replica1","base_url":"https://127.0.0.1:61830/solr","node_name":"127.0.0.1:61830_solr","state":"recovering"}
[junit4] 2> 348658 INFO (qtp379183-3999) [n:127.0.0.1:61829_solr ]
o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node3, state: recovering,
checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 348658 INFO (qtp379183-3999) [n:127.0.0.1:61829_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores
params={nodeName=127.0.0.1:61830_solr&onlyIfLeaderActive=true&core=test_col_shard2_replica2&coreNodeName=core_node3&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2}
status=0 QTime=1002
[junit4] 2> 349038 INFO
(OverseerCollectionConfigSetProcessor-96727990617047053-127.0.0.1:61844_solr-n_0000000000)
[n:127.0.0.1:61844_solr ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 355632 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.c.RecoveryStrategy Attempting to PeerSync
from [https://127.0.0.1:61833/solr/test_col_shard1_replica2/] -
recoveringAfterStartup=[true]
[junit4] 2> 355632 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.u.PeerSync PeerSync:
core=test_col_shard1_replica1 url=https://127.0.0.1:61844/solr START
replicas=[https://127.0.0.1:61833/solr/test_col_shard1_replica2/] nUpdates=100
[junit4] 2> 355641 INFO (qtp26371412-4017) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2]
o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0
result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0,
maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 355641 INFO (qtp26371412-4017) [n:127.0.0.1:61833_solr
c:test_col s:shard1 r:core_node2 x:test_col_shard1_replica2] o.a.s.c.S.Request
[test_col_shard1_replica2] webapp=/solr path=/get
params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2}
status=0 QTime=2
[junit4] 2> 355643 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.u.IndexFingerprint IndexFingerprint
millis:0.0 result:{maxVersionSpecified=9223372036854775807,
maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0,
maxDoc=0}
[junit4] 2> 355643 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.u.PeerSync We are already in sync. No need to
do a PeerSync
[junit4] 2> 355643 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 355643 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.u.DirectUpdateHandler2 No uncommitted
changes. Skipping IW.commit.
[junit4] 2> 355644 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 355644 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.c.RecoveryStrategy PeerSync stage of recovery
was successful.
[junit4] 2> 355644 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.c.RecoveryStrategy Replaying updates buffered
during PeerSync.
[junit4] 2> 355644 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.c.RecoveryStrategy No replay needed.
[junit4] 2> 355644 INFO
(recoveryExecutor-897-thread-1-processing-n:127.0.0.1:61844_solr
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node1)
[n:127.0.0.1:61844_solr c:test_col s:shard1 r:core_node1
x:test_col_shard1_replica1] o.a.s.c.RecoveryStrategy Registering as Active
after recovery.
[junit4] 2> 355647 INFO
(zkCallback-902-thread-1-processing-n:127.0.0.1:61829_solr)
[n:127.0.0.1:61829_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 355647 INFO
(zkCallback-904-thread-2-processing-n:127.0.0.1:61844_solr)
[n:127.0.0.1:61844_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 355647 INFO
(zkCallback-903-thread-1-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 355647 INFO
(zkCallback-906-thread-1-processing-n:127.0.0.1:61830_solr)
[n:127.0.0.1:61830_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 355659 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.c.RecoveryStrategy Attempting to PeerSync
from [https://127.0.0.1:61829/solr/test_col_shard2_replica2/] -
recoveringAfterStartup=[true]
[junit4] 2> 355659 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.u.PeerSync PeerSync:
core=test_col_shard2_replica1 url=https://127.0.0.1:61830/solr START
replicas=[https://127.0.0.1:61829/solr/test_col_shard2_replica2/] nUpdates=100
[junit4] 2> 355666 INFO (qtp379183-4047) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2]
o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0
result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0,
maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 355666 INFO (qtp379183-4047) [n:127.0.0.1:61829_solr
c:test_col s:shard2 r:core_node4 x:test_col_shard2_replica2] o.a.s.c.S.Request
[test_col_shard2_replica2] webapp=/solr path=/get
params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2}
status=0 QTime=1
[junit4] 2> 355668 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.u.IndexFingerprint IndexFingerprint
millis:0.0 result:{maxVersionSpecified=9223372036854775807,
maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0,
maxDoc=0}
[junit4] 2> 355668 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.u.PeerSync We are already in sync. No need to
do a PeerSync
[junit4] 2> 355668 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 355668 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.u.DirectUpdateHandler2 No uncommitted
changes. Skipping IW.commit.
[junit4] 2> 355668 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 355668 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.c.RecoveryStrategy PeerSync stage of recovery
was successful.
[junit4] 2> 355668 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.c.RecoveryStrategy Replaying updates buffered
during PeerSync.
[junit4] 2> 355668 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.c.RecoveryStrategy No replay needed.
[junit4] 2> 355668 INFO
(recoveryExecutor-899-thread-1-processing-n:127.0.0.1:61830_solr
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node3)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.c.RecoveryStrategy Registering as Active
after recovery.
[junit4] 2> 355774 INFO
(zkCallback-902-thread-1-processing-n:127.0.0.1:61829_solr)
[n:127.0.0.1:61829_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 355775 INFO
(zkCallback-904-thread-2-processing-n:127.0.0.1:61844_solr)
[n:127.0.0.1:61844_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 355775 INFO
(zkCallback-903-thread-1-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 355775 INFO
(zkCallback-906-thread-1-processing-n:127.0.0.1:61830_solr)
[n:127.0.0.1:61830_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 356666 INFO (qtp555947-4031) [n:127.0.0.1:61844_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={replicationFactor=2&property.schema=schema15.xml&property.config=solrconfig-distrib-update-processor-chains.xml&collection.configName=solrCloudCollectionConfig&name=test_col&action=CREATE&
[...truncated too long message...]
c:test_col s:shard1 r:core_node1 x:test_col_shard1_replica1] o.a.s.c.SolrCore
[test_col_shard1_replica1] CLOSING SolrCore
org.apache.solr.core.SolrCore@10701d3
[junit4] 2> 443032 INFO (coreCloseExecutor-1928-thread-1)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.c.SolrCore [test_col_shard2_replica1]
CLOSING SolrCore org.apache.solr.core.SolrCore@1290717
[junit4] 2> 443036 INFO (coreCloseExecutor-1928-thread-1)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.u.DirectUpdateHandler2 Committing on
IndexWriter close.
[junit4] 2> 443036 INFO (coreCloseExecutor-1928-thread-1)
[n:127.0.0.1:61830_solr c:test_col s:shard2 r:core_node3
x:test_col_shard2_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with
IW:org.apache.solr.update.SolrIndexWriter@1ce567c
[junit4] 2> 443040 INFO
(zkCallback-904-thread-4-processing-n:127.0.0.1:61844_solr)
[n:127.0.0.1:61844_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (5) -> (4)
[junit4] 2> 443410 WARN
(zkCallback-905-thread-2-processing-n:127.0.0.1:61845_solr)
[n:127.0.0.1:61845_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 443410 INFO
(zkCallback-902-thread-2-processing-n:127.0.0.1:61829_solr)
[n:127.0.0.1:61829_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 443411 INFO
(zkCallback-904-thread-6-processing-n:127.0.0.1:61844_solr)
[n:127.0.0.1:61844_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [4])
[junit4] 2> 443411 INFO
(zkCallback-906-thread-2-processing-n:127.0.0.1:61830_solr)
[n:127.0.0.1:61830_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 443411 INFO
(zkCallback-903-thread-2-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test_col/state.json] for collection [test_col] has occurred -
updating... (live nodes size: [5])
[junit4] 2> 443413 INFO (jetty-launcher-880-thread-8) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@67f866{/solr,null,UNAVAILABLE}
[junit4] 2> 443422 INFO
(zkCallback-903-thread-3-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (5) -> (4)
[junit4] 2> 443422 INFO
(zkCallback-906-thread-3-processing-n:127.0.0.1:61830_solr)
[n:127.0.0.1:61830_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (5) -> (4)
[junit4] 2> 443422 INFO
(zkCallback-902-thread-4-processing-n:127.0.0.1:61829_solr)
[n:127.0.0.1:61829_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (5) -> (4)
[junit4] 2> 443468 INFO (jetty-launcher-880-thread-10) [ ]
o.a.s.c.Overseer Overseer
(id=96727990617047053-127.0.0.1:61844_solr-n_0000000000) closing
[junit4] 2> 443481 INFO
(OverseerStateUpdate-96727990617047053-127.0.0.1:61844_solr-n_0000000000)
[n:127.0.0.1:61844_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:61844_solr
[junit4] 2> 443577 INFO (jetty-launcher-880-thread-10) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@58265d{/solr,null,UNAVAILABLE}
[junit4] 2> 443579 INFO
(zkCallback-903-thread-2-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (1)
[junit4] 2> 443582 INFO (jetty-launcher-880-thread-6) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@2e0cc3{/solr,null,UNAVAILABLE}
[junit4] 2> 443584 INFO
(zkCallback-903-thread-3-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:61833_solr
[junit4] 2> 443593 WARN
(zkCallback-903-thread-2-processing-n:127.0.0.1:61833_solr)
[n:127.0.0.1:61833_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 445075 WARN
(zkCallback-902-thread-4-processing-n:127.0.0.1:61829_solr)
[n:127.0.0.1:61829_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 445075 INFO (jetty-launcher-880-thread-9) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@ff4f3a{/solr,null,UNAVAILABLE}
[junit4] 2> 445094 INFO (jetty-launcher-880-thread-7) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@d43230{/solr,null,UNAVAILABLE}
[junit4] 2> 445096 INFO
(SUITE-TestTolerantUpdateProcessorCloud-seed#[A1779DCC8FE98CA2]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:61825 61825
[junit4] 2> 445099 INFO (Thread-786) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:61825 61825
[junit4] 2> 445101 WARN (Thread-786) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/aliases.json
[junit4] 2> 5 /solr/security.json
[junit4] 2> 4
/solr/configs/solrCloudCollectionConfig/managed-schema
[junit4] 2> 4 /solr/configs/solrCloudCollectionConfig
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/clusterstate.json
[junit4] 2> 6 /solr/clusterprops.json
[junit4] 2> 4 /solr/collections/test_col/state.json
[junit4] 2> 2
/solr/overseer_elect/election/96727990617047053-127.0.0.1:61844_solr-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 87 /solr/overseer/collection-queue-work
[junit4] 2> 21 /solr/overseer/queue
[junit4] 2> 6 /solr/live_nodes
[junit4] 2> 6 /solr/collections
[junit4] 2> 3 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> 445101 INFO
(SUITE-TestTolerantUpdateProcessorCloud-seed#[A1779DCC8FE98CA2]-worker) [ ]
o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.TestTolerantUpdateProcessorCloud_A1779DCC8FE98CA2-001
[junit4] 2> Oct 08, 2016 6:41:46 PM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked
thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70),
sim=RandomSimilarity(queryNorm=true): {}, locale=cs, timezone=SystemV/MST7
[junit4] 2> NOTE: Windows 10 10.0 x86/Oracle Corporation 1.8.0_102
(32-bit)/cpus=3,threads=1,free=220805280,total=477364224
[junit4] 2> NOTE: All tests run in this JVM: [TestDistributedGrouping,
TestNumericTerms64, BJQParserTest, TlogReplayBufferedWhileIndexingTest,
SuggestComponentContextFilterQueryTest, EchoParamsTest, TestFastWriter,
SharedFSAutoReplicaFailoverTest, SaslZkACLProviderTest,
SolrCoreCheckLockOnStartupTest, RollingRestartTest, TestMaxScoreQueryParser,
BasicDistributedZk2Test, SignatureUpdateProcessorFactoryTest,
LeaderInitiatedRecoveryOnShardRestartTest, TestSubQueryTransformerCrossCore,
SpellCheckComponentTest, CheckHdfsIndexTest, TestRestManager,
ReplicationFactorTest, TestReloadAndDeleteDocs, UUIDFieldTest,
ConnectionReuseTest, TestDFRSimilarityFactory, TestQueryWrapperFilter,
TestSolrConfigHandlerCloud, TestBulkSchemaConcurrent, TestBadConfig,
ConvertedLegacyTest, TestQueryUtils, TestAnalyzedSuggestions,
TestFieldSortValues, TestDocSet, CircularListTest, CSVRequestHandlerTest,
TestSolrIndexConfig, NotRequiredUniqueKeyTest, TestRandomFlRTGCloud,
UpdateRequestProcessorFactoryTest, TestExclusionRuleCollectionAccess,
TestDocBasedVersionConstraints, TestRestoreCore,
TestDistributedStatsComponentCardinality, AnalyticsQueryTest,
TestRequestForwarding, TestTolerantUpdateProcessorCloud]
[junit4] Completed [72/635 (1!)] on J1 in 101.83s, 19 tests, 1 error <<<
FAILURES!
[...truncated 1826 lines...]
[junit4] JVM J1: stdout was not empty, see:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\temp\junit4-J1-20161008_183416_542.sysout
[junit4] >>> JVM J1 emitted unexpected output (verbatim) ----
[junit4] java.lang.OutOfMemoryError: GC overhead limit exceeded
[junit4] Dumping heap to
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\heapdumps\java_pid6836.hprof
...
[junit4] Heap dump file created [438613486 bytes in 2.109 secs]
[junit4] <<< JVM J1: EOF ----
[...truncated 11027 lines...]
BUILD FAILED
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\build.xml:765: The
following error occurred while executing this line:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\build.xml:717: Some of
the tests produced a heap dump, but did not fail. Maybe a suppressed
OutOfMemoryError? Dumps created:
* java_pid6836.hprof
Total time: 92 minutes 0 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
