You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2020/02/18 22:02:26 UTC
[JENKINS] Lucene-Solr-8.x-MacOSX (64bit/jdk-13.0.2) - Build # 658 -
Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-MacOSX/658/
Java: 64bit/jdk-13.0.2 -XX:+UseCompressedOops -XX:+UseParallelGC
2 tests failed.
FAILED: org.apache.solr.cloud.TestStressLiveNodes.testStress
Error Message:
Test abandoned because suite timeout was reached.
Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
at __randomizedtesting.SeedInfo.seed([5CDB1026AC4BF2CF]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.TestStressLiveNodes
Error Message:
Suite timeout exceeded (>= 7200000 msec).
Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
at __randomizedtesting.SeedInfo.seed([5CDB1026AC4BF2CF]:0)
Build Log:
[...truncated 16299 lines...]
[junit4] Suite: org.apache.solr.cloud.TestStressLiveNodes
[junit4] 2> 425239 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/server/solr/configsets/_default/conf'
[junit4] 2> 425239 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J4/temp/solr.cloud.TestStressLiveNodes_5CDB1026AC4BF2CF-001/data-dir-27-001
[junit4] 2> 425239 WARN (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=16 numCloses=16
[junit4] 2> 425240 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 425240 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 425241 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 425241 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J4/temp/solr.cloud.TestStressLiveNodes_5CDB1026AC4BF2CF-001/tempDir-001
[junit4] 2> 425242 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 425242 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 425242 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 425346 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:61858
[junit4] 2> 425346 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:61858
[junit4] 2> 425346 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:61858
[junit4] 2> 425346 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 61858
[junit4] 2> 425349 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 425355 INFO (zkConnectionManagerCallback-936-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 425355 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 425361 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 425366 INFO (zkConnectionManagerCallback-938-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 425366 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 425367 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 425372 INFO (zkConnectionManagerCallback-940-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 425372 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 425489 WARN (jetty-launcher-941-thread-1) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 425489 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 425489 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 425489 INFO (jetty-launcher-941-thread-1) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 13.0.2+8
[junit4] 2> 425493 INFO (jetty-launcher-941-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 425493 INFO (jetty-launcher-941-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 425493 INFO (jetty-launcher-941-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 425494 INFO (jetty-launcher-941-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7899d6a2{/solr,null,AVAILABLE}
[junit4] 2> 425495 INFO (jetty-launcher-941-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@60608936{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:61871}
[junit4] 2> 425495 INFO (jetty-launcher-941-thread-1) [ ] o.e.j.s.Server Started @425660ms
[junit4] 2> 425495 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=61871}
[junit4] 2> 425495 ERROR (jetty-launcher-941-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 425495 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 425495 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.5.0
[junit4] 2> 425495 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 425495 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr
[junit4] 2> 425495 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-18T19:43:44.929964Z
[junit4] 2> 425497 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 425501 INFO (zkConnectionManagerCallback-943-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 425502 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 425503 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 425660 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 425661 WARN (jetty-launcher-941-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@ebf3c82[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 425661 WARN (jetty-launcher-941-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@ebf3c82[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 425668 WARN (jetty-launcher-941-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@56a8e75f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 425668 WARN (jetty-launcher-941-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@56a8e75f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 425669 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:61858/solr
[junit4] 2> 425671 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 425677 INFO (zkConnectionManagerCallback-950-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 425677 INFO (jetty-launcher-941-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 425783 INFO (jetty-launcher-941-thread-1) [n:127.0.0.1:61871_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 425789 INFO (zkConnectionManagerCallback-952-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 425790 INFO (jetty-launcher-941-thread-1) [n:127.0.0.1:61871_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 426105 INFO (jetty-launcher-941-thread-1) [n:127.0.0.1:61871_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:61871_solr
[junit4] 2> 426108 INFO (jetty-launcher-941-thread-1) [n:127.0.0.1:61871_solr ] o.a.s.c.Overseer Overseer (id=72087992534564869-127.0.0.1:61871_solr-n_0000000000) starting
[junit4] 2> 426124 INFO (OverseerStateUpdate-72087992534564869-127.0.0.1:61871_solr-n_0000000000) [n:127.0.0.1:61871_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:61871_solr
[junit4] 2> 426125 INFO (jetty-launcher-941-thread-1) [n:127.0.0.1:61871_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:61871_solr
[junit4] 2> 426131 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 426138 INFO (jetty-launcher-941-thread-1) [n:127.0.0.1:61871_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 426140 WARN (jetty-launcher-941-thread-1) [n:127.0.0.1:61871_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 426179 INFO (jetty-launcher-941-thread-1) [n:127.0.0.1:61871_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 426296 INFO (jetty-launcher-941-thread-1) [n:127.0.0.1:61871_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_61871.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@18dccadf
[junit4] 2> 426332 INFO (jetty-launcher-941-thread-1) [n:127.0.0.1:61871_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_61871.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@18dccadf
[junit4] 2> 426333 INFO (jetty-launcher-941-thread-1) [n:127.0.0.1:61871_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_61871.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@18dccadf
[junit4] 2> 426339 INFO (jetty-launcher-941-thread-1) [n:127.0.0.1:61871_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J4/temp/solr.cloud.TestStressLiveNodes_5CDB1026AC4BF2CF-001/tempDir-001/node1/.
[junit4] 2> 426393 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=1
[junit4] 2> 426394 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 426402 INFO (zkConnectionManagerCallback-961-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 426402 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 426410 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 426417 INFO (SUITE-TestStressLiveNodes-seed#[5CDB1026AC4BF2CF]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:61858/solr ready
[junit4] 2> 426458 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testStress
[junit4] 2> 426460 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 426467 INFO (zkConnectionManagerCallback-963-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 426467 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 426580 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=0, numThreads=5 numNodesPerThread=2
[junit4] 2> 426583 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 426589 INFO (zkConnectionManagerCallback-965-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 426589 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 426593 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 426599 INFO (zkConnectionManagerCallback-967-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 426599 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 426601 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 426607 INFO (zkConnectionManagerCallback-969-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 426607 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 426610 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 426616 INFO (zkConnectionManagerCallback-971-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 426616 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 426619 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 426622 INFO (zkConnectionManagerCallback-973-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 426623 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 426643 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (6)
[junit4] 2> 426643 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (6)
[junit4] 2> 426647 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (6) -> (11)
[junit4] 2> 426648 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (6) -> (11)
[junit4] 2> 426653 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 426659 INFO (zkConnectionManagerCallback-975-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 426659 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 426874 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (11) -> (9)
[junit4] 2> 426875 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (11) -> (9)
[junit4] 2> 426879 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (7)
[junit4] 2> 426988 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (7)
[junit4] 2> 426990 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (5)
[junit4] 2> 426991 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (5)
[junit4] 2> 427204 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (3)
[junit4] 2> 427205 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (3)
[junit4] 2> 427205 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 427205 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 427308 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 427314 INFO (zkConnectionManagerCallback-977-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 427314 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 427428 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=1, numThreads=5 numNodesPerThread=3
[junit4] 2> 427429 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 427434 INFO (zkConnectionManagerCallback-979-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 427434 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 427435 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 427441 INFO (zkConnectionManagerCallback-981-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 427441 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 427443 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 427448 INFO (zkConnectionManagerCallback-983-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 427448 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 427452 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 427459 INFO (zkConnectionManagerCallback-985-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 427459 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 427460 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 427467 INFO (zkConnectionManagerCallback-987-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 427467 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 427487 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (5)
[junit4] 2> 427488 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (5)
[junit4] 2> 427493 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (9)
[junit4] 2> 427498 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (10)
[junit4] 2> 427500 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (12)
[junit4] 2> 427506 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (10) -> (14)
[junit4] 2> 427508 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (12) -> (15)
[junit4] 2> 427508 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (14) -> (16)
[junit4] 2> 427510 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (15) -> (16)
[junit4] 2> 427515 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 427520 INFO (zkConnectionManagerCallback-989-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 427520 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 427640 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (16) -> (13)
[junit4] 2> 427747 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (16) -> (13)
[junit4] 2> 427749 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (13) -> (10)
[junit4] 2> 427749 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (13) -> (10)
[junit4] 2> 427853 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (10) -> (7)
[junit4] 2> 427853 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (10) -> (7)
[junit4] 2> 427959 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (4)
[junit4] 2> 427959 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (4)
[junit4] 2> 428065 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (1)
[junit4] 2> 428065 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (1)
[junit4] 2> 428167 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 428171 INFO (zkConnectionManagerCallback-991-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 428171 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 428284 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=2, numThreads=2 numNodesPerThread=5
[junit4] 2> 428285 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 428290 INFO (zkConnectionManagerCallback-993-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 428290 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 428291 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 428295 INFO (zkConnectionManagerCallback-995-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 428295 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 428301 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 428301 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 428303 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 428303 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 428305 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (7)
[junit4] 2> 428306 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (7)
[junit4] 2> 428308 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (9)
[junit4] 2> 428309 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (9)
[junit4] 2> 428309 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 428314 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (11)
[junit4] 2> 428317 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (11)
[junit4] 2> 428319 INFO (zkConnectionManagerCallback-997-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 428319 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 428426 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (11) -> (6)
[junit4] 2> 428426 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (11) -> (6)
[junit4] 2> 428530 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (6) -> (1)
[junit4] 2> 428530 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (6) -> (1)
[junit4] 2> 428633 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 428642 INFO (zkConnectionManagerCallback-999-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 428642 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 428753 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=3, numThreads=2 numNodesPerThread=1
[junit4] 2> 428754 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 428759 INFO (zkConnectionManagerCallback-1001-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 428759 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 428761 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 428764 INFO (zkConnectionManagerCallback-1003-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 428764 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 428770 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 428771 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 428771 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 428774 INFO (zkConnectionManagerCallback-1005-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 428774 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 428984 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 428984 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 429087 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 429088 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 429088 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 429092 INFO (zkConnectionManagerCallback-1007-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 429093 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 429201 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=4, numThreads=2 numNodesPerThread=3
[junit4] 2> 429202 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 429205 INFO (zkConnectionManagerCallback-1009-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 429205 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 429206 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 429211 INFO (zkConnectionManagerCallback-1011-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 429211 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 429217 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 429217 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 429220 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 429220 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 429222 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (7)
[junit4] 2> 429222 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (7)
[junit4] 2> 429223 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 429226 INFO (zkConnectionManagerCallback-1013-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 429226 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 429342 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (4)
[junit4] 2> 429342 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (4)
[junit4] 2> 429448 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (1)
[junit4] 2> 429448 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (1)
[junit4] 2> 429566 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 429571 INFO (zkConnectionManagerCallback-1015-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 429571 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 429679 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=5, numThreads=4 numNodesPerThread=4
[junit4] 2> 429682 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 429685 INFO (zkConnectionManagerCallback-1017-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 429685 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 429692 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 429703 INFO (zkConnectionManagerCallback-1019-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 429703 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 429704 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 429714 INFO (zkConnectionManagerCallback-1021-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 429715 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 429717 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 429727 INFO (zkConnectionManagerCallback-1023-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 429727 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 429739 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (5)
[junit4] 2> 429752 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (5)
[junit4] 2> 429778 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (8)
[junit4] 2> 429781 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (8)
[junit4] 2> 429793 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (8) -> (9)
[junit4] 2> 429793 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (8) -> (10)
[junit4] 2> 429796 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (13)
[junit4] 2> 429797 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (10) -> (13)
[junit4] 2> 429809 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (13) -> (16)
[junit4] 2> 429811 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (13) -> (17)
[junit4] 2> 429812 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (16) -> (17)
[junit4] 2> 429813 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 429818 INFO (zkConnectionManagerCallback-1025-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 429818 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 430034 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (17) -> (13)
[junit4] 2> 430034 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (17) -> (13)
[junit4] 2> 430035 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (13) -> (9)
[junit4] 2> 430035 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (13) -> (9)
[junit4] 2> 430147 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (5)
[junit4] 2> 430147 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (5)
[junit4] 2> 430257 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (1)
[junit4] 2> 430257 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (1)
[junit4] 2> 430367 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 430389 INFO (zkConnectionManagerCallback-1027-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 430390 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 430523 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=6, numThreads=5 numNodesPerThread=1
[junit4] 2> 430546 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 430553 INFO (zkConnectionManagerCallback-1029-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 430556 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 430560 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 430609 INFO (zkConnectionManagerCallback-1031-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 430611 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 430613 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 430623 INFO (zkConnectionManagerCallback-1033-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 430623 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 430626 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 430635 INFO (zkConnectionManagerCallback-1035-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 430635 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 430639 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 430657 INFO (zkConnectionManagerCallback-1037-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 430659 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 430674 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (4)
[junit4] 2> 430674 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 430676 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (6)
[junit4] 2> 430676 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (6)
[junit4] 2> 430690 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 430691 INFO (zkConnectionManagerCallback-1039-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 430698 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 430933 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (6) -> (5)
[junit4] 2> 430933 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (6) -> (5)
[junit4] 2> 430934 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 430938 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 431145 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 431145 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 431259 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 431261 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 431367 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 431367 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 431372 INFO (zkConnectionManagerCallback-1041-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 431372 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 431478 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=7, numThreads=3 numNodesPerThread=1
[junit4] 2> 431479 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 431483 INFO (zkConnectionManagerCallback-1043-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 431483 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 431484 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 431489 INFO (zkConnectionManagerCallback-1045-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 431489 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 431491 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 431496 INFO (zkConnectionManagerCallback-1047-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 431496 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 431502 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (4)
[junit4] 2> 431504 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (4)
[junit4] 2> 431505 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 431509 INFO (zkConnectionManagerCallback-1049-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 431509 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 431618 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 431619 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 431840 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 431840 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 431950 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 431951 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 431951 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 431956 INFO (zkConnectionManagerCallback-1051-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 431956 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 432061 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=8, numThreads=2 numNodesPerThread=4
[junit4] 2> 432063 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 432068 INFO (zkConnectionManagerCallback-1053-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 432068 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 432073 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 432081 INFO (zkConnectionManagerCallback-1055-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 432081 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 432085 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 432093 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 432106 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 432106 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 432110 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (7)
[junit4] 2> 432111 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (7)
[junit4] 2> 432112 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (9)
[junit4] 2> 432113 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (9)
[junit4] 2> 432114 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 432119 INFO (zkConnectionManagerCallback-1057-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 432119 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 432226 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (5)
[junit4] 2> 432226 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (5)
[junit4] 2> 432336 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (1)
[junit4] 2> 432336 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (1)
[junit4] 2> 432445 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 432449 INFO (zkConnectionManagerCallback-1059-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 432449 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 432558 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=9, numThreads=2 numNodesPerThread=2
[junit4] 2> 432560 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 432564 INFO (zkConnectionManagerCallback-1061-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 432564 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 432565 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 432571 INFO (zkConnectionManagerCallback-1063-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 432571 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 432576 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 432576 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 432579 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 432579 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 432579 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 432584 INFO (zkConnectionManagerCallback-1065-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 432584 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 432701 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (3)
[junit4] 2> 432805 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (3)
[junit4] 2> 432808 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 432808 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 432911 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 432918 INFO (zkConnectionManagerCallback-1067-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 432918 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 433024 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=10, numThreads=2 numNodesPerThread=2
[junit4] 2> 433026 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 433031 INFO (zkConnectionManagerCallback-1069-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 433032 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 433033 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 433044 INFO (zkConnectionManagerCallback-1071-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 433044 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 433050 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 433051 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 433055 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 433055 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 433057 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 433063 INFO (zkConnectionManagerCallback-1073-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 433063 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 433180 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (3)
[junit4] 2> 433181 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (3)
[junit4] 2> 433392 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 433392 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 433392 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 433397 INFO (zkConnectionManagerCallback-1075-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 433397 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 433503 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=11, numThreads=5 numNodesPerThread=1
[junit4] 2> 433504 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 433508 INFO (zkConnectionManagerCallback-1077-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 433508 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 433509 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 433515 INFO (zkConnectionManagerCallback-1079-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 433515 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 433517 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 433521 INFO (zkConnectionManagerCallback-1081-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 433523 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 433525 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 433529 INFO (zkConnectionManagerCallback-1083-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 433529 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 433531 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 433535 INFO (zkConnectionManagerCallback-1085-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 433535 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 433541 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (5)
[junit4] 2> 433542 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (6)
[junit4] 2> 433544 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 433544 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 433549 INFO (zkConnectionManagerCallback-1087-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 433549 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 433657 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (6) -> (5)
[junit4] 2> 433657 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (6) -> (5)
[junit4] 2> 433873 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 433874 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 433876 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 433876 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 433981 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 434082 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 434083 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 434188 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 434192 INFO (zkConnectionManagerCallback-1089-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 434192 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 434316 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=12, numThreads=5 numNodesPerThread=3
[junit4] 2> 434317 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 434324 INFO (zkConnectionManagerCallback-1091-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 434324 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 434326 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 434333 INFO (zkConnectionManagerCallback-1093-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 434333 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 434334 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 434340 INFO (zkConnectionManagerCallback-1095-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 434340 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 434341 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 434346 INFO (zkConnectionManagerCallback-1097-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 434347 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 434353 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 434361 INFO (zkConnectionManagerCallback-1099-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 434361 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 434372 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (6)
[junit4] 2> 434372 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (6)
[junit4] 2> 434378 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (6) -> (11)
[junit4] 2> 434379 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (6) -> (11)
[junit4] 2> 434385 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (11) -> (16)
[junit4] 2> 434386 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (11) -> (16)
[junit4] 2> 434388 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 434392 INFO (zkConnectionManagerCallback-1101-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 434392 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 434508 INFO (zkCallback-951-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (16) -> (13)
[junit4] 2> 434612 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (16) -> (13)
[junit4] 2> 434727 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (13) -> (10)
[junit4] 2> 434727 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (13) -> (10)
[junit4] 2> 434730 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (10) -> (7)
[junit4] 2> 434730 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (10) -> (7)
[junit4] 2> 434838 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (4)
[junit4] 2> 434838 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (4)
[junit4] 2> 434972 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (1)
[junit4] 2> 434972 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (1)
[junit4] 2> 435059 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 435068 INFO (zkConnectionManagerCallback-1103-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 435068 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 435182 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=13, numThreads=5 numNodesPerThread=4
[junit4] 2> 435184 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 435192 INFO (zkConnectionManagerCallback-1105-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 435192 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 435195 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 435200 INFO (zkConnectionManagerCallback-1107-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 435200 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 435203 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 435208 INFO (zkConnectionManagerCallback-1109-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 435208 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 435210 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 435247 INFO (zkConnectionManagerCallback-1111-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 435247 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 435249 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 435255 INFO (zkConnectionManagerCallback-1113-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 435255 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 435265 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (5)
[junit4] 2> 435266 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (6)
[junit4] 2> 435271 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (6) -> (10)
[junit4] 2> 435271 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (9)
[junit4] 2> 435275 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (14)
[junit4] 2> 435277 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (10) -> (15)
[junit4] 2> 435283 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (15) -> (20)
[junit4] 2> 435291 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (14) -> (20)
[junit4] 2> 435295 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (20) -> (21)
[junit4] 2> 435295 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (20) -> (21)
[junit4] 2> 435297 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 435310 INFO (zkConnectionManagerCallback-1115-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 435312 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 435548 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (21) -> (17)
[junit4] 2> 435549 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (21) -> (17)
[junit4] 2> 435550 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (17) -> (13)
[junit4] 2> 435551 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (17) -> (13)
[junit4] 2> 435656 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (13) -> (9)
[junit4] 2> 435656 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (13) -> (9)
[junit4] 2> 435766 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (5)
[junit4] 2> 435888 INFO (zkCallback-960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (5)
[junit4] 2> 435974 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 435974 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (1)
[junit4] 2> 435981 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (1)
[junit4] 2> 435982 INFO (zkConnectionManagerCallback-1117-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 435982 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 436101 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=14, numThreads=2 numNodesPerThread=2
[junit4] 2> 436103 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 436108 INFO (zkConnectionManagerCallback-1119-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 436108 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 436110 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 436114 INFO (zkConnectionManagerCallback-1121-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 436116 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 436128 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 436129 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 436133 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 436133 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 436139 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 436148 INFO (zkConnectionManagerCallback-1123-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 436149 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 436262 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (3)
[junit4] 2> 436263 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (3)
[junit4] 2> 436467 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 436468 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 436471 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 436480 INFO (zkConnectionManagerCallback-1125-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 436480 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 436591 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=15, numThreads=2 numNodesPerThread=4
[junit4] 2> 436593 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 436601 INFO (zkConnectionManagerCallback-1127-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 436601 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 436602 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 436610 INFO (zkConnectionManagerCallback-1129-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 436610 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 436617 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 436617 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 436620 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 436621 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (5)
[junit4] 2> 436624 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (7)
[junit4] 2> 436625 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (7)
[junit4] 2> 436631 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 436632 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (9)
[junit4] 2> 436632 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (9)
[junit4] 2> 436638 INFO (zkConnectionManagerCallback-1131-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 436638 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 436746 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (5)
[junit4] 2> 436746 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (5)
[junit4] 2> 436956 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (1)
[junit4] 2> 436956 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (1)
[junit4] 2> 436956 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 436963 INFO (zkConnectionManagerCallback-1133-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 436963 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 437069 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=16, numThreads=3 numNodesPerThread=4
[junit4] 2> 437070 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 437075 INFO (zkConnectionManagerCallback-1135-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 437075 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 437077 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 437081 INFO (zkConnectionManagerCallback-1137-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 437081 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 437082 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 437086 INFO (zkConnectionManagerCallback-1139-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 437086 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 437094 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (4)
[junit4] 2> 437094 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (4)
[junit4] 2> 437099 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (6)
[junit4] 2> 437099 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (6)
[junit4] 2> 437101 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (6) -> (7)
[junit4] 2> 437102 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (6) -> (8)
[junit4] 2> 437103 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (7) -> (9)
[junit4] 2> 437104 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (8) -> (10)
[junit4] 2> 437106 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (12)
[junit4] 2> 437108 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (10) -> (13)
[junit4] 2> 437110 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 437110 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (12) -> (13)
[junit4] 2> 437115 INFO (zkConnectionManagerCallback-1141-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 437115 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 437325 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (13) -> (9)
[junit4] 2> 437325 INFO (zkCallback-951-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (13) -> (9)
[junit4] 2> 437327 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (5)
[junit4] 2> 437327 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (9) -> (5)
[junit4] 2> 437537 INFO (zkCallback-960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (1)
[junit4] 2> 437537 INFO (zkCallback-951-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (1)
[junit4] 2> 437537 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 437542 INFO (zkConnectionManagerCallback-1143-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 437543 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 437648 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.TestStressLiveNodes preparing parallel adds to live nodes: iter=17, numThreads=2 numNodesPerThread=5
[junit4] 2> 437649 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 437653 INFO (zkConnectionManagerCallback-1145-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 437653 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 437654 INFO (TEST-TestStressLiveNodes.testStress-seed#[5CDB1026AC4BF2CF]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 437657 INFO (zkConnectionManagerCallback-1147-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient ha
[...truncated too long message...]
tive Method)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2081)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1177)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[junit4] 2> at java.base@13.0.2/java.lang.Thread.run(Thread.java:830)
[junit4] 2> 9) Thread[id=4545, name=Connector-Scheduler-60608936-1, state=WAITING, group=TGRP-TestStressLiveNodes]
[junit4] 2> at java.base@13.0.2/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2081)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1170)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[junit4] 2> at java.base@13.0.2/java.lang.Thread.run(Thread.java:830)
[junit4] 2> 10) Thread[id=2895, name=qtp1856469650-2895, state=TIMED_WAITING, group=TGRP-TestStressLiveNodes]
[junit4] 2> at java.base@13.0.2/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:235)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] 2> at app//org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:382)
[junit4] 2> at app//org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.idleJobPoll(QueuedThreadPool.java:875)
[junit4] 2> at app//org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:925)
[junit4] 2> at java.base@13.0.2/java.lang.Thread.run(Thread.java:830)
[junit4] 2> 11) Thread[id=2890, name=qtp1856469650-2890, state=RUNNABLE, group=TGRP-TestStressLiveNodes]
[junit4] 2> at java.base@13.0.2/sun.nio.ch.KQueue.poll(Native Method)
[junit4] 2> at java.base@13.0.2/sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:122)
[junit4] 2> at java.base@13.0.2/sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:124)
[junit4] 2> at java.base@13.0.2/sun.nio.ch.SelectorImpl.select(SelectorImpl.java:141)
[junit4] 2> at app//org.eclipse.jetty.io.ManagedSelector$SelectorProducer.select(ManagedSelector.java:472)
[junit4] 2> at app//org.eclipse.jetty.io.ManagedSelector$SelectorProducer.produce(ManagedSelector.java:409)
[junit4] 2> at app//org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produceTask(EatWhatYouKill.java:360)
[junit4] 2> at app//org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:184)
[junit4] 2> at app//org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
[junit4] 2> at app//org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:135)
[junit4] 2> at app//org.eclipse.jetty.io.ManagedSelector$$Lambda$214/0x0000000800e3a840.run(Unknown Source)
[junit4] 2> at app//org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
[junit4] 2> at app//org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
[junit4] 2> at java.base@13.0.2/java.lang.Thread.run(Thread.java:830)
[junit4] 2> 12) Thread[id=2893, name=qtp1856469650-2893, state=TIMED_WAITING, group=TGRP-TestStressLiveNodes]
[junit4] 2> at java.base@13.0.2/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:235)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] 2> at app//org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:382)
[junit4] 2> at app//org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.idleJobPoll(QueuedThreadPool.java:875)
[junit4] 2> at app//org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:925)
[junit4] 2> at java.base@13.0.2/java.lang.Thread.run(Thread.java:830)
[junit4] 2> 13) Thread[id=2892, name=qtp1856469650-2892, state=TIMED_WAITING, group=TGRP-TestStressLiveNodes]
[junit4] 2> at java.base@13.0.2/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:235)
[junit4] 2> at java.base@13.0.2/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
[junit4] 2> at app//org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:382)
[junit4] 2> at app//org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.idleJobPoll(QueuedThreadPool.java:875)
[junit4] 2> at app//org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:925)
[junit4] 2> at java.base@13.0.2/java.lang.Thread.run(Thread.java:830)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {}, docValues:{}, maxPointsInLeafNode=1770, maxMBSortInHeap=5.844537021424156, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@3cbe27a4), locale=bez-TZ, timezone=America/Dawson
[junit4] 2> NOTE: Mac OS X 10.14.6 x86_64/AdoptOpenJDK 13.0.2 (64-bit)/cpus=6,threads=13,free=263723736,total=410517504
[junit4] 2> NOTE: All tests run in this JVM: [SuggestComponentContextFilterQueryTest, SolrCmdDistributorTest, TestStressReorder, TestHighlightDedupGrouping, TestFilteredDocIdSet, TestCollapseQParserPlugin, TestDocTermOrdsUninvertLimit, TestDeleteCollectionOnDownNodes, TestChildDocTransformer, NodeMutatorTest, TestDocSet, TestRealTimeGet, ZkCollectionPropsCachingTest, TestDistributedGrouping, TestMultiValuedNumericRangeQuery, TestSearchPerf, SimpleFacetsTest, TestSolr4Spatial2, TestNestedDocsSort, ShardRoutingCustomTest, MergeStrategyTest, BasicAuthStandaloneTest, TestCloudPivotFacet, TestSolrQueryParser, CleanupOldIndexTest, DocExpirationUpdateProcessorFactoryTest, TestSystemIdResolver, AsyncCallRequestStatusResponseTest, ClassificationUpdateProcessorTest, CollectionPropsTest, TestStressLiveNodes]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestStressLiveNodes -Dtests.seed=5CDB1026AC4BF2CF -Dtests.slow=true -Dtests.locale=bez-TZ -Dtests.timezone=America/Dawson -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J4 | TestStressLiveNodes (suite) <<<
[junit4] > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4] > at __randomizedtesting.SeedInfo.seed([5CDB1026AC4BF2CF]:0)
[junit4] Completed [843/901 (1!)] on J4 in 7213.02s, 1 test, 2 errors <<< FAILURES!
[...truncated 48133 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-MacOSX/658/consoleText
[repro] Revision: 01c9c68cc8dffe496f9a15de253c6f81cd2d2c16
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC"
[repro] Repro line: ant test -Dtestcase=TestStressLiveNodes -Dtests.method=testStress -Dtests.seed=5CDB1026AC4BF2CF -Dtests.slow=true -Dtests.locale=bez-TZ -Dtests.timezone=America/Dawson -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[repro] Repro line: ant test -Dtestcase=TestStressLiveNodes -Dtests.seed=5CDB1026AC4BF2CF -Dtests.slow=true -Dtests.locale=bez-TZ -Dtests.timezone=America/Dawson -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[repro] JUnit rest result XML files will be moved to: ./repro-reports
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] TestStressLiveNodes
[repro] ant compile-test
[...truncated 3463 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestStressLiveNodes" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=5CDB1026AC4BF2CF -Dtests.slow=true -Dtests.locale=bez-TZ -Dtests.timezone=America/Dawson -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[...truncated 86 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.TestStressLiveNodes
[repro] Exiting with code 0
[...truncated 73 lines...]
[JENKINS] Lucene-Solr-8.x-MacOSX (64bit/jdk1.8.0) - Build # 660 -
Failure!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-MacOSX/660/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
All tests passed
Build Log:
[...truncated 68484 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/build.xml:634: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/build.xml:101: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build.xml:624: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build.xml:156: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/solr-ref-guide/build.xml:289: Java returned: 255
Total time: 69 minutes 33 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[JENKINS-Experimental-GC] Lucene-Solr-8.x-MacOSX (64bit/jdk-14-rc)
- Build # 659 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-MacOSX/659/
Java: 64bit/jdk-14-rc -XX:-UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseZGC
2 tests failed.
FAILED: org.apache.solr.cloud.SystemCollectionCompatTest.testBackCompat
Error Message:
re-indexing warning not found
Stack Trace:
java.lang.AssertionError: re-indexing warning not found
at __randomizedtesting.SeedInfo.seed([3715C2F833883102:47E0615153409874]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.solr.cloud.SystemCollectionCompatTest.testBackCompat(SystemCollectionCompatTest.java:215)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:832)
FAILED: org.apache.solr.cloud.SystemCollectionCompatTest.testBackCompat
Error Message:
re-indexing warning not found
Stack Trace:
java.lang.AssertionError: re-indexing warning not found
at __randomizedtesting.SeedInfo.seed([3715C2F833883102:47E0615153409874]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.solr.cloud.SystemCollectionCompatTest.testBackCompat(SystemCollectionCompatTest.java:215)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:832)
Build Log:
[...truncated 14264 lines...]
[junit4] Suite: org.apache.solr.cloud.SystemCollectionCompatTest
[junit4] 2> 599379 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/server/solr/configsets/_default/conf'
[junit4] 2> 599380 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.SystemCollectionCompatTest_3715C2F833883102-001/data-dir-43-001
[junit4] 2> 599380 WARN (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=2 numCloses=2
[junit4] 2> 599380 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 599381 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 599381 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 599382 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.SystemCollectionCompatTest_3715C2F833883102-001/tempDir-001
[junit4] 2> 599382 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 599384 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 599384 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 599486 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:62053
[junit4] 2> 599486 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:62053
[junit4] 2> 599486 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:62053
[junit4] 2> 599486 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 62053
[junit4] 2> 599490 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 599495 INFO (zkConnectionManagerCallback-3472-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 599495 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 599502 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 599508 INFO (zkConnectionManagerCallback-3474-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 599508 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 599510 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 599515 INFO (zkConnectionManagerCallback-3476-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 599516 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 599631 WARN (jetty-launcher-3477-thread-2) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 599631 WARN (jetty-launcher-3477-thread-1) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 599631 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 599631 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 599631 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 599631 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 599631 INFO (jetty-launcher-3477-thread-2) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 14+36-1461
[junit4] 2> 599631 INFO (jetty-launcher-3477-thread-1) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 14+36-1461
[junit4] 2> 599635 INFO (jetty-launcher-3477-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 599635 INFO (jetty-launcher-3477-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 599635 INFO (jetty-launcher-3477-thread-2) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 599635 INFO (jetty-launcher-3477-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@c3d1f3{/solr,null,AVAILABLE}
[junit4] 2> 599636 INFO (jetty-launcher-3477-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 599636 INFO (jetty-launcher-3477-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 599636 INFO (jetty-launcher-3477-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 599636 INFO (jetty-launcher-3477-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@d20244e{/solr,null,AVAILABLE}
[junit4] 2> 599636 INFO (jetty-launcher-3477-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4b84d400{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:62059}
[junit4] 2> 599636 INFO (jetty-launcher-3477-thread-2) [ ] o.e.j.s.Server Started @599753ms
[junit4] 2> 599636 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=62059}
[junit4] 2> 599636 ERROR (jetty-launcher-3477-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 599636 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 599636 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.5.0
[junit4] 2> 599636 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 599636 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr
[junit4] 2> 599636 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-19T01:52:35.437708Z
[junit4] 2> 599636 INFO (jetty-launcher-3477-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@52e856a4{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:62060}
[junit4] 2> 599654 INFO (jetty-launcher-3477-thread-1) [ ] o.e.j.s.Server Started @599770ms
[junit4] 2> 599654 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=62060}
[junit4] 2> 599654 ERROR (jetty-launcher-3477-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 599654 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 599655 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.5.0
[junit4] 2> 599655 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 599655 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr
[junit4] 2> 599655 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-19T01:52:35.456113Z
[junit4] 2> 599655 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 599656 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 599661 INFO (zkConnectionManagerCallback-3481-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 599661 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 599661 INFO (zkConnectionManagerCallback-3479-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 599661 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 599662 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 599665 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 599999 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 600003 WARN (jetty-launcher-3477-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@552bf69b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 600004 WARN (jetty-launcher-3477-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@552bf69b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 600035 WARN (jetty-launcher-3477-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@d1f675f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 600035 WARN (jetty-launcher-3477-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@d1f675f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 600047 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62053/solr
[junit4] 2> 600051 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 600054 INFO (zkConnectionManagerCallback-3489-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 600055 INFO (jetty-launcher-3477-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 600068 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 600081 WARN (jetty-launcher-3477-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@5fd4a909[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 600081 WARN (jetty-launcher-3477-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@5fd4a909[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 600105 WARN (jetty-launcher-3477-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@3bf90935[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 600110 WARN (jetty-launcher-3477-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@3bf90935[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 600114 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62053/solr
[junit4] 2> 600122 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 600125 INFO (zkConnectionManagerCallback-3495-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 600126 INFO (jetty-launcher-3477-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 600177 INFO (jetty-launcher-3477-thread-2) [n:127.0.0.1:62059_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 600187 INFO (zkConnectionManagerCallback-3497-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 600187 INFO (jetty-launcher-3477-thread-2) [n:127.0.0.1:62059_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 600282 INFO (jetty-launcher-3477-thread-1) [n:127.0.0.1:62060_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 600284 INFO (zkConnectionManagerCallback-3499-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 600284 INFO (jetty-launcher-3477-thread-1) [n:127.0.0.1:62060_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 601265 INFO (jetty-launcher-3477-thread-2) [n:127.0.0.1:62059_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:62059_solr
[junit4] 2> 601276 INFO (jetty-launcher-3477-thread-2) [n:127.0.0.1:62059_solr ] o.a.s.c.Overseer Overseer (id=72089442879799303-127.0.0.1:62059_solr-n_0000000000) starting
[junit4] 2> 601361 INFO (OverseerStateUpdate-72089442879799303-127.0.0.1:62059_solr-n_0000000000) [n:127.0.0.1:62059_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:62059_solr
[junit4] 2> 601364 INFO (jetty-launcher-3477-thread-2) [n:127.0.0.1:62059_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62059_solr
[junit4] 2> 601380 INFO (OverseerStateUpdate-72089442879799303-127.0.0.1:62059_solr-n_0000000000) [n:127.0.0.1:62059_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 601438 INFO (jetty-launcher-3477-thread-2) [n:127.0.0.1:62059_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 601439 WARN (jetty-launcher-3477-thread-2) [n:127.0.0.1:62059_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 601485 INFO (jetty-launcher-3477-thread-2) [n:127.0.0.1:62059_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 601538 INFO (jetty-launcher-3477-thread-2) [n:127.0.0.1:62059_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62059.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4352f275
[junit4] 2> 601554 INFO (jetty-launcher-3477-thread-2) [n:127.0.0.1:62059_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62059.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4352f275
[junit4] 2> 601554 INFO (jetty-launcher-3477-thread-2) [n:127.0.0.1:62059_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62059.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4352f275
[junit4] 2> 601556 INFO (jetty-launcher-3477-thread-2) [n:127.0.0.1:62059_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.SystemCollectionCompatTest_3715C2F833883102-001/tempDir-001/node2/.
[junit4] 2> 601736 INFO (jetty-launcher-3477-thread-1) [n:127.0.0.1:62060_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 601773 INFO (jetty-launcher-3477-thread-1) [n:127.0.0.1:62060_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:62060_solr as DOWN
[junit4] 2> 601787 INFO (jetty-launcher-3477-thread-1) [n:127.0.0.1:62060_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 601787 INFO (jetty-launcher-3477-thread-1) [n:127.0.0.1:62060_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62060_solr
[junit4] 2> 601799 INFO (zkCallback-3496-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 601799 INFO (zkCallback-3498-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 601825 INFO (jetty-launcher-3477-thread-1) [n:127.0.0.1:62060_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 601825 WARN (jetty-launcher-3477-thread-1) [n:127.0.0.1:62060_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 601879 INFO (jetty-launcher-3477-thread-1) [n:127.0.0.1:62060_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 601906 INFO (jetty-launcher-3477-thread-1) [n:127.0.0.1:62060_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62060.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4352f275
[junit4] 2> 601920 INFO (jetty-launcher-3477-thread-1) [n:127.0.0.1:62060_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62060.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4352f275
[junit4] 2> 601920 INFO (jetty-launcher-3477-thread-1) [n:127.0.0.1:62060_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62060.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4352f275
[junit4] 2> 601922 INFO (jetty-launcher-3477-thread-1) [n:127.0.0.1:62060_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.SystemCollectionCompatTest_3715C2F833883102-001/tempDir-001/node1/.
[junit4] 2> 601965 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 601966 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 601973 INFO (zkConnectionManagerCallback-3512-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 601973 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 601986 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 601995 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62053/solr ready
[junit4] 2> 602203 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[3715C2F833883102]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBackCompat
[junit4] 2> 602213 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params name=.system&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 602264 INFO (OverseerThreadFactory-1806-thread-1-processing-n:127.0.0.1:62059_solr) [n:127.0.0.1:62059_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection .system
[junit4] 2> 602451 INFO (OverseerStateUpdate-72089442879799303-127.0.0.1:62059_solr-n_0000000000) [n:127.0.0.1:62059_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:62059/solr",
[junit4] 2> "node_name":"127.0.0.1:62059_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 602462 INFO (OverseerStateUpdate-72089442879799303-127.0.0.1:62059_solr-n_0000000000) [n:127.0.0.1:62059_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:62060/solr",
[junit4] 2> "node_name":"127.0.0.1:62060_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 602670 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr x:.system_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 602670 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n2&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 602670 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr x:.system_shard1_replica_n1 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 602698 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.5.0
[junit4] 2> 602698 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.5.0
[junit4] 2> 602707 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 602707 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 602712 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 602712 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 602716 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 602716 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 602718 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/.system/managed-schema
[junit4] 2> 602718 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Managed schema znode at /configs/.system/managed-schema already exists - no need to create it
[junit4] 2> 602721 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n2' using configuration from configset .system, trusted=true
[junit4] 2> 602722 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62060.solr.core..system.shard1.replica_n2' (registry 'solr.core..system.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4352f275
[junit4] 2> 602723 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [[.system_shard1_replica_n2] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.SystemCollectionCompatTest_3715C2F833883102-001/tempDir-001/node1/.system_shard1_replica_n2], dataDir=[/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.SystemCollectionCompatTest_3715C2F833883102-001/tempDir-001/node1/./.system_shard1_replica_n2/data/]
[junit4] 2> 602728 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/.system/schema.xml to /configs/.system/schema.xml.bak
[junit4] 2> 602728 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n1' using configuration from configset .system, trusted=true
[junit4] 2> 602729 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62059.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4352f275
[junit4] 2> 602729 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [[.system_shard1_replica_n1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.SystemCollectionCompatTest_3715C2F833883102-001/tempDir-001/node2/.system_shard1_replica_n1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.SystemCollectionCompatTest_3715C2F833883102-001/tempDir-001/node2/./.system_shard1_replica_n1/data/]
[junit4] 2> 602823 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 602823 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 602827 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 602827 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 602829 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommitted docs;
[junit4] 2> 602829 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 602831 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommitted docs;
[junit4] 2> 602831 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 602832 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@32701282[.system_shard1_replica_n2] main]
[junit4] 2> 602834 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2ce04cc4[.system_shard1_replica_n1] main]
[junit4] 2> 602846 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system
[junit4] 2> 602847 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 602848 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema
[junit4] 2> 602850 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system
[junit4] 2> 602850 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 0 from ZooKeeper
[junit4] 2> 602853 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 602853 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 602853 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema
[junit4] 2> 602855 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 602855 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 602855 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1658928138714873856
[junit4] 2> 602857 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 602857 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 6 ms
[junit4] 2> 602857 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 602857 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1658928138716971008
[junit4] 2> 602861 INFO (searcherExecutor-1815-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [.system_shard1_replica_n2] Registered new searcher Searcher@32701282[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 602863 INFO (searcherExecutor-1816-thread-1-processing-n:127.0.0.1:62059_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@2ce04cc4[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 602878 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node4=0}, version=0}
[junit4] 2> 602878 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/.system/leaders/shard1
[junit4] 2> 602886 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node3=0, core_node4=0}, version=1}
[junit4] 2> 602887 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/.system/leaders/shard1
[junit4] 2> 602909 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 602909 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 602909 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:62060/solr/.system_shard1_replica_n2/
[junit4] 2> 602910 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.PeerSync PeerSync: core=.system_shard1_replica_n2 url=http://127.0.0.1:62060/solr START replicas=[http://127.0.0.1:62059/solr/.system_shard1_replica_n1/] nUpdates=100
[junit4] 2> 602917 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.PeerSync PeerSync: core=.system_shard1_replica_n2 url=http://127.0.0.1:62060/solr DONE. We have no versions. sync failed.
[junit4] 2> 602920 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 602921 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 602921 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] 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> 602921 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/.system/leaders/shard1/leader after winning as /collections/.system/leader_elect/shard1/election/72089442879799304-core_node4-n_0000000000
[junit4] 2> 602940 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:62060/solr/.system_shard1_replica_n2/ shard1
[junit4] 2> 603050 INFO (zkCallback-3498-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 603050 INFO (zkCallback-3498-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 603052 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 603056 INFO (qtp1546625873-9591) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n2&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=386
[junit4] 2> 603166 INFO (zkCallback-3498-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 603166 INFO (zkCallback-3498-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 603167 INFO (zkCallback-3498-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 603924 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1254
[junit4] 2> 603933 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas
[junit4] 2> 604026 INFO (zkCallback-3498-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 604026 INFO (zkCallback-3498-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 604026 INFO (zkCallback-3498-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 604026 INFO (zkCallback-3496-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 604027 INFO (zkCallback-3496-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 604030 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=.system&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=1817
[junit4] 2> 604031 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[3715C2F833883102]) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: .system
[junit4] 2> 604038 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[3715C2F833883102]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 604042 INFO (zkConnectionManagerCallback-3519-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 604042 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[3715C2F833883102]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 604046 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[3715C2F833883102]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 604050 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[3715C2F833883102]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62053/solr ready
[junit4] 2> 604059 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node3=1, core_node4=1}, version=2}
[junit4] 2> 604066 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:62060/solr/.system_shard1_replica_n2/&wt=javabin&version=2}{add=[1705b25a99eT62g7wu4c84y1ina986p105rai (1658928139974213632)]} 0 2
[junit4] 2> 604067 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1705b25a99eT62g7wu4c84y1ina986p105rai (1658928139974213632)]} 0 12
[junit4] 2> 604069 INFO (qtp1546625873-9588) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1658928139987845120,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 604069 INFO (qtp1546625873-9588) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@74eee0e6 commitCommandVersion:1658928139987845120
[junit4] 2> 604071 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1658928139989942272,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 604071 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@e7c2424 commitCommandVersion:1658928139989942272
[junit4] 2> 604074 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4e302f42[.system_shard1_replica_n1] main]
[junit4] 2> 604074 INFO (qtp1546625873-9588) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@26722126[.system_shard1_replica_n2] main]
[junit4] 2> 604075 INFO (qtp1546625873-9588) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 604075 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 604076 INFO (searcherExecutor-1816-thread-1-processing-n:127.0.0.1:62059_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@4e302f42[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.5.0):C1:[diagnostics={os=Mac OS X, java.vendor=Oracle Corporation, java.version=14, java.vm.version=14+36-1461, lucene.version=8.5.0, os.arch=x86_64, java.runtime.version=14+36-1461, source=flush, os.version=10.14.6, timestamp=1582077159873}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 604076 INFO (searcherExecutor-1815-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [.system_shard1_replica_n2] Registered new searcher Searcher@26722126[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.5.0):C1:[diagnostics={os=Mac OS X, java.vendor=Oracle Corporation, java.version=14, java.vm.version=14+36-1461, lucene.version=8.5.0, os.arch=x86_64, java.runtime.version=14+36-1461, source=flush, os.version=10.14.6, timestamp=1582077159873}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 604077 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:62060/solr/.system_shard1_replica_n2/&commit_end_point=replicas&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 6
[junit4] 2> 604077 INFO (qtp1546625873-9588) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n2] webapp=/solr path=/update params={_stateVer_=.system:5&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 9
[junit4] 2> 604084 INFO (qtp1546625873-9593) [n:127.0.0.1:62060_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=true&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604087 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema params={wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604098 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SchemaManager managed schema loaded . version : 1
[junit4] 2> 604100 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 604103 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 604104 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ZkController Persisted config data to node /configs/.system/schema.xml.bak
[junit4] 2> 604107 INFO (Thread-1303) [ ] o.a.s.c.SolrCore config update listener called for core .system_shard1_replica_n1
[junit4] 2> 604107 INFO (Thread-1304) [ ] o.a.s.c.SolrCore config update listener called for core .system_shard1_replica_n2
[junit4] 2> 604112 INFO (Thread-1304) [ ] o.a.s.c.SolrCore core reload .system_shard1_replica_n2
[junit4] 2> 604119 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.5.0
[junit4] 2> 604127 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 604130 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 604130 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.CoreContainer Reloading SolrCore '.system_shard1_replica_n2' using configuration from configset .system
[junit4] 2> 604226 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62060.solr.core..system.shard1.replica_n2' (registry 'solr.core..system.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4352f275
[junit4] 2> 604226 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [[.system_shard1_replica_n2] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.SystemCollectionCompatTest_3715C2F833883102-001/tempDir-001/node1/.system_shard1_replica_n2], dataDir=[/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.SystemCollectionCompatTest_3715C2F833883102-001/tempDir-001/node1/./.system_shard1_replica_n2/data/]
[junit4] 2> 604278 INFO (OverseerCollectionConfigSetProcessor-72089442879799303-127.0.0.1:62059_solr-n_0000000000) [n:127.0.0.1:62059_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> 604299 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommitted docs;
[junit4] 2> 604299 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 604301 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@30d67499[.system_shard1_replica_n2] main]
[junit4] 2> 604307 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system
[junit4] 2> 604308 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 604308 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema
[junit4] 2> 604310 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604310 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 604324 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 604325 INFO (searcherExecutor-1825-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [.system_shard1_replica_n2] Registered new searcher Searcher@30d67499[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.5.0):C1:[diagnostics={os=Mac OS X, java.vendor=Oracle Corporation, java.version=14, java.vm.version=14+36-1461, lucene.version=8.5.0, os.arch=x86_64, java.runtime.version=14+36-1461, source=flush, os.version=10.14.6, timestamp=1582077159873}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 604326 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7e8475ee[.system_shard1_replica_n2] main]
[junit4] 2> 604328 INFO (qtp1546625873-9594) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Waiting up to 599 secs for 1 replicas to apply schema update version 2 for collection .system
[junit4] 2> 604329 INFO (searcherExecutor-1825-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [.system_shard1_replica_n2] Registered new searcher Searcher@7e8475ee[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.5.0):C1:[diagnostics={java.vendor=Oracle Corporation, os=Mac OS X, java.version=14, java.vm.version=14+36-1461, lucene.version=8.5.0, os.arch=x86_64, java.runtime.version=14+36-1461, source=flush, os.version=10.14.6, timestamp=1582077159873}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 604333 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604334 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604334 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 604334 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604336 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604337 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604337 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 604337 INFO (Thread-1304) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.5.0
[junit4] 2> 604337 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604338 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604339 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604339 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 604340 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604341 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604342 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604342 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604342 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604343 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604344 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604344 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604345 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604346 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604346 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604346 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604347 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604347 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604348 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604348 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604348 INFO (Thread-1304) [ ] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 604348 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604349 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604350 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604350 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604350 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604351 INFO (Thread-1304) [ ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 604351 INFO (Thread-1304) [ ] o.a.s.c.CoreContainer Reloading SolrCore '.system_shard1_replica_n2' using configuration from configset .system
[junit4] 2> 604351 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604352 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604352 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604352 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604353 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604354 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604354 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604354 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604357 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604357 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604357 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604358 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604359 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604359 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604359 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604360 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604361 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604361 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604361 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604362 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604363 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604363 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604363 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604364 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604364 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604365 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604365 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604365 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604366 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604367 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604367 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604367 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604368 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604369 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604369 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604369 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604370 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604370 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604370 INFO (qtp1162031832-9585) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604371 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604372 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604372 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604372 INFO (qtp1162031832-9589) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604373 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604374 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604374 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 604374 INFO (qtp1162031832-9590) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 604375 ERROR (managedSchemaExecutor-1829-thread-1-processing-n:127.0.0.1:62060_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:62060_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:62059/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 604376 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 604376 INFO (qtp1162031832-9587) [n:127.0.0.1:62059_sol
[...truncated too long message...]
onCompatTest -Dtests.method=testBackCompat -Dtests.seed=3715C2F833883102 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=ca-ES -Dtests.timezone=Asia/Bishkek -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 202s J3 | SystemCollectionCompatTest.testBackCompat <<<
[junit4] > Throwable #1: java.lang.AssertionError: re-indexing warning not found
[junit4] > at __randomizedtesting.SeedInfo.seed([3715C2F833883102:47E0615153409874]:0)
[junit4] > at org.apache.solr.cloud.SystemCollectionCompatTest.testBackCompat(SystemCollectionCompatTest.java:215)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:564)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:832)
[junit4] 2> 213207 INFO (jetty-closer-114507-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1423117741
[junit4] 2> 213207 INFO (jetty-closer-114507-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:64230_solr
[junit4] 2> 213208 INFO (jetty-closer-114507-thread-1) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 213208 INFO (jetty-closer-114507-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:64230_solr as DOWN
[junit4] 2> 213322 INFO (jetty-closer-114507-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 213323 INFO (jetty-closer-114507-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@75b43ea3: rootName = solr_64230, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@6184cc1d
[junit4] 2> 213328 INFO (jetty-closer-114507-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 213328 INFO (jetty-closer-114507-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@356c39db: rootName = solr_64230, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@6560acb0
[junit4] 2> 213329 INFO (jetty-closer-114507-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 213329 INFO (jetty-closer-114507-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5a94f4d2: rootName = solr_64230, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@54ee3a44
[junit4] 2> 213330 INFO (jetty-closer-114507-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 213330 INFO (closeThreadPool-114511-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72089667131932679-127.0.0.1:64230_solr-n_0000000001) closing
[junit4] 2> 213330 INFO (OverseerStateUpdate-72089667131932679-127.0.0.1:64230_solr-n_0000000001) [n:127.0.0.1:64230_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:64230_solr
[junit4] 2> 213331 INFO (OverseerAutoScalingTriggerThread-72089667131932679-127.0.0.1:64230_solr-n_0000000001) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 213334 INFO (closeThreadPool-114511-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72089667131932679-127.0.0.1:64230_solr-n_0000000001) closing
[junit4] 2> 213437 INFO (jetty-closer-114507-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72089667131932679-127.0.0.1:64230_solr-n_0000000001) closing
[junit4] 2> 213439 INFO (jetty-closer-114507-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@24282f5{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
[junit4] 2> 213440 INFO (jetty-closer-114507-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@161c9ae9{/solr,null,UNAVAILABLE}
[junit4] 2> 213440 INFO (jetty-closer-114507-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 213441 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 213668 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 9 /solr/configs/.system/managed-schema
[junit4] 2> 9 /solr/collections/.system/terms/shard1
[junit4] 2> 8 /solr/clusterprops.json
[junit4] 2> 8 /solr/aliases.json
[junit4] 2> 6 /solr/configs/.system
[junit4] 2> 5 /solr/collections/.system/collectionprops.json
[junit4] 2> 3 /solr/collections/.system/state.json
[junit4] 2> 2 /solr/packages.json
[junit4] 2> 2 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 29 /solr/collections/.system/state.json
[junit4] 2> 8 /solr/clusterstate.json
[junit4] 2> 5 /solr/aliases.json
[junit4] 2> 3 /solr/configs/.system/managed-schema
[junit4] 2> 2 /solr/autoscaling.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 28 /solr/overseer/queue
[junit4] 2> 18 /solr/overseer/collection-queue-work
[junit4] 2> 16 /solr/collections
[junit4] 2> 15 /solr/live_nodes
[junit4] 2> 2 /solr/autoscaling/events/.scheduled_maintenance
[junit4] 2> 2 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 2 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> 213673 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:64202
[junit4] 2> 213673 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:64202
[junit4] 2> 213673 INFO (SUITE-SystemCollectionCompatTest-seed#[3715C2F833883102]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 64202
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.SystemCollectionCompatTest_3715C2F833883102-001
[junit4] 2> Feb 19, 2020 2:53:06 AM 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(Lucene84): {id=PostingsFormat(name=LuceneVarGapDocFreqInterval), type=PostingsFormat(name=Asserting)}, docValues:{timestamp_l=DocValuesFormat(name=Asserting), _version_=DocValuesFormat(name=Direct), time_l=DocValuesFormat(name=Direct), timestamp=DocValuesFormat(name=Lucene80)}, maxPointsInLeafNode=1938, maxMBSortInHeap=6.253646633132144, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@5e1f0a93), locale=ca-ES, timezone=Asia/Bishkek
[junit4] 2> NOTE: Mac OS X 10.14.6 x86_64/Oracle Corporation 14 (64-bit)/cpus=6,threads=2,free=371195904,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [SystemCollectionCompatTest]
[junit4] Completed [5/5 (1!)] on J3 in 212.68s, 1 test, 1 failure <<< FAILURES!
[...truncated 13 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/lucene/common-build.xml:1594: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/lucene/common-build.xml:1121: There were test failures: 5 suites, 5 tests, 1 failure [seed: 3715C2F833883102]
Total time: 4 minutes 6 seconds
[repro] Setting last failure code to 256
[repro] Failures w/original seeds:
[repro] 1/5 failed: org.apache.solr.cloud.SystemCollectionCompatTest
[repro] Exiting with code 256
+ mv lucene/build lucene/build.repro
+ mv solr/build solr/build.repro
+ mv lucene/build.orig lucene/build
+ mv solr/build.orig solr/build
Archiving artifacts
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[WARNINGS] Parsing warnings in console log with parser Java Compiler (javac)
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
No credentials specified
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
<Git Blamer> Using GitBlamer to create author and commit information for all warnings.
<Git Blamer> GIT_COMMIT=b01d7cb79a00aae89c108cdf3185971ee68ecda6, workspace=/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX
[WARNINGS] Computing warning deltas based on reference build #658
Recording test results
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2