Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java8/884/
1 tests failed.
FAILED:
org.apache.solr.cloud.OverseerTest.testExternalClusterStateChangeBehavior
Error Message:
Illegal state, was: down expected:active clusterState:live
nodes:[]collections:{c1=DocCollection(c1)={ "shards":{"shard1":{
"parent":null, "range":null, "state":"active",
"replicas":{"core_node1":{ "base_url":"http://127.0.0.1/solr",
"node_name":"node1", "core":"core1", "roles":"",
"state":"down"}}}}, "router":{"name":"implicit"}},
test=LazyCollectionRef(test)}
Stack Trace:
java.lang.AssertionError: Illegal state, was: down expected:active
clusterState:live nodes:[]collections:{c1=DocCollection(c1)={
"shards":{"shard1":{
"parent":null,
"range":null,
"state":"active",
"replicas":{"core_node1":{
"base_url":"http://127.0.0.1/solr",
"node_name":"node1",
"core":"core1",
"roles":"",
"state":"down"}}}},
"router":{"name":"implicit"}}, test=LazyCollectionRef(test)}
at
__randomizedtesting.SeedInfo.seed([31D689C6D24391D6:59C88A2A30D3CB98]:0)
at org.junit.Assert.fail(Assert.java:93)
at
org.apache.solr.cloud.AbstractDistribZkTestBase.verifyReplicaStatus(AbstractDistribZkTestBase.java:236)
at
org.apache.solr.cloud.OverseerTest.testExternalClusterStateChangeBehavior(OverseerTest.java:1277)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11146 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-trunk-Java8/solr/build/solr-core/test/J2/temp/solr.cloud.OverseerTest_31D689C6D24391D6-001/init-core-data-001
[junit4] 2> 902686 INFO
(SUITE-OverseerTest-seed#[31D689C6D24391D6]-worker) [ ] o.a.s.SolrTestCaseJ4
Randomized ssl (false) and clientAuth (true)
[junit4] 2> 902686 INFO
(SUITE-OverseerTest-seed#[31D689C6D24391D6]-worker) [ ] o.a.s.SolrTestCaseJ4
####initCore
[junit4] 2> 902686 INFO
(SUITE-OverseerTest-seed#[31D689C6D24391D6]-worker) [ ] o.a.s.SolrTestCaseJ4
####initCore end
[junit4] 2> 902688 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testDoubleAssignment
[junit4] 2> 902688 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 902689 INFO (Thread-2255) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 902689 INFO (Thread-2255) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 902789 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ZkTestServer start zk server on port:42429
[junit4] 2> 902789 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 902789 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 902791 INFO (zkCallback-920-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@55d488b name:ZooKeeperConnection
Watcher:127.0.0.1:42429/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 902791 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 902792 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 902792 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 902792 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 902794 INFO (zkCallback-921-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@5601a8f name:ZooKeeperConnection
Watcher:127.0.0.1:42429 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 902794 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 902794 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 902795 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 902795 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 902796 INFO (zkCallback-922-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@3ec48b61
name:ZooKeeperConnection Watcher:127.0.0.1:42429 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 902796 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 902797 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 902797 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 902799 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 902800 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /collections
[junit4] 2> 902801 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 902802 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 902803 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 902804 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 902805 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0)
[junit4] 2> 902806 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 902807 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 902813 INFO (zkCallback-923-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@8d5518f name:ZooKeeperConnection
Watcher:127.0.0.1:42429/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 902813 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 902813 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 902814 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 902815 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0)
[junit4] 2> 902816 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /live_nodes/node1
[junit4] 2> 902817 INFO (zkCallback-920-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [0])
[junit4] 2> 902817 INFO (zkCallback-923-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [0])
[junit4] 2> 902817 INFO (zkCallback-920-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 902818 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 902818 INFO (zkCallback-923-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 902820 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 902821 INFO (zkCallback-924-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@4c6f66d2
name:ZooKeeperConnection Watcher:127.0.0.1:42429/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 902821 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 902821 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 902821 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=600000&connTimeout=60000&retry=true
[junit4] 2> 902823 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /overseer_elect
[junit4] 2> 902824 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
[junit4] 2> 902825 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 902825 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.LeaderElector Joined leadership election with path:
/overseer_elect/election/95459380581761028-127.0.0.1:42429_solr-n_0000000000
[junit4] 2> 902825 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:42429_solr
[junit4] 2> 902825 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
[junit4] 2> 902826 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.Overseer Overseer
(id=95459380581761028-127.0.0.1:42429_solr-n_0000000000) starting
[junit4] 2> 902827 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /overseer/queue
[junit4] 2> 902829 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
[junit4] 2> 902830 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
[junit4] 2> 902832 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
[junit4] 2> 902833 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
[junit4] 2> 902835 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
[junit4] 2> 902837 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.OverseerAutoReplicaFailoverThread Starting
OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 902838 INFO
(OverseerCollectionConfigSetProcessor-95459380581761028-127.0.0.1:42429_solr-n_0000000000)
[ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer
operations
[junit4] 2> 902838 INFO
(OverseerStateUpdate-95459380581761028-127.0.0.1:42429_solr-n_0000000000) [
] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 902839 INFO
(OverseerStateUpdate-95459380581761028-127.0.0.1:42429_solr-n_0000000000) [
] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 902840 INFO
(OverseerStateUpdate-95459380581761028-127.0.0.1:42429_solr-n_0000000000) [
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 902841 INFO
(OverseerStateUpdate-95459380581761028-127.0.0.1:42429_solr-n_0000000000) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"} current state version: 0
[junit4] 2> 902842 INFO
(OverseerStateUpdate-95459380581761028-127.0.0.1:42429_solr-n_0000000000) [
] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 902842 INFO
(OverseerStateUpdate-95459380581761028-127.0.0.1:42429_solr-n_0000000000) [
] o.a.s.c.o.ClusterStateMutator building a new cName: collection1
[junit4] 2> 902842 INFO
(OverseerStateUpdate-95459380581761028-127.0.0.1:42429_solr-n_0000000000) [
] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 902843 INFO (zkCallback-924-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 902843 INFO (zkCallback-920-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 902843 INFO (zkCallback-923-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 903339 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 903340 INFO (zkCallback-920-thread-1) [ ]
o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/collections], has occurred - updating...
[junit4] 2> 903340 INFO (zkCallback-923-thread-1) [ ]
o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/collections], has occurred - updating...
[junit4] 2> 903341 INFO (zkCallback-924-thread-1) [ ]
o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/collections], has occurred - updating...
[junit4] 2> 903346 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.LeaderElector Joined leadership election with path:
/collections/collection1/leader_elect/shard1/election/95459380581761027-node1_core1-n_0000000000
[junit4] 2> 903346 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard1
[junit4] 2> 903348 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node
/collections/collection1/leaders/shard1/leader after winning as
/collections/collection1/leader_elect/shard1/election/95459380581761027-node1_core1-n_0000000000
[junit4] 2> 903350 INFO
(OverseerStateUpdate-95459380581761028-127.0.0.1:42429_solr-n_0000000000) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"http://node1/solr/",
[junit4] 2> "core":"core1",
[junit4] 2> "state":"active"} current state version: 1
[junit4] 2> 903351 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (1)
[junit4] 2> 903351 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ElectionContext Canceling election
/collections/collection1/leader_elect/shard1/election/95459380581761027-node1_core1-n_0000000000
[junit4] 2> 903351 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ShardLeaderElectionContextBase Removing leader registration node on
cancel: /collections/collection1/leaders/shard1/leader 1
[junit4] 2> 903352 INFO (zkCallback-920-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [1])
[junit4] 2> 903352 INFO (zkCallback-924-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [1])
[junit4] 2> 903352 INFO (zkCallback-923-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [1])
[junit4] 2> 903352 INFO (zkCallback-920-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 903352 INFO (zkCallback-924-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 903352 INFO (zkCallback-923-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 903353 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 903354 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 903355 INFO (zkCallback-927-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@52ced9cd
name:ZooKeeperConnection Watcher:127.0.0.1:42429/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 903355 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 903355 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 903356 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 903357 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0)
[junit4] 2> 903358 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /live_nodes/node1
[junit4] 2> 903359 INFO (zkCallback-927-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [0])
[junit4] 2> 903359 INFO (zkCallback-920-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [0])
[junit4] 2> 903359 INFO (zkCallback-924-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [0])
[junit4] 2> 903359 INFO (zkCallback-920-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 903360 INFO (zkCallback-927-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 903360 INFO (zkCallback-924-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 903361 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 903361 INFO
(OverseerStateUpdate-95459380581761028-127.0.0.1:42429_solr-n_0000000000) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"} current state version: 1
[junit4] 2> 903361 INFO
(OverseerStateUpdate-95459380581761028-127.0.0.1:42429_solr-n_0000000000) [
] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 903361 INFO
(OverseerStateUpdate-95459380581761028-127.0.0.1:42429_solr-n_0000000000) [
] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered
[junit4] 2> 903363 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.LeaderElector Joined leadership election with path:
/collections/collection1/leader_elect/shard1/election/95459380581761029-node1_core1-n_0000000001
[junit4] 2> 903363 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node
/collections/collection1/leaders/shard1/leader after winning as
/collections/collection1/leader_elect/shard1/election/95459380581761029-node1_core1-n_0000000001
[junit4] 2> 903365 INFO
(OverseerStateUpdate-95459380581761028-127.0.0.1:42429_solr-n_0000000000) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"http://node1/solr/",
[junit4] 2> "core":"core1",
[junit4] 2> "state":"active"} current state version: 1
[junit4] 2> 903467 INFO (zkCallback-927-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 903467 INFO (zkCallback-924-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 903467 INFO (zkCallback-920-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 903468 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (1)
[junit4] 2> 903469 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ElectionContext Canceling election
/collections/collection1/leader_elect/shard1/election/95459380581761029-node1_core1-n_0000000001
[junit4] 2> 903469 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ShardLeaderElectionContextBase Removing leader registration node on
cancel: /collections/collection1/leaders/shard1/leader 2
[junit4] 2> 903470 INFO (zkCallback-927-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [1])
[junit4] 2> 903470 INFO (zkCallback-920-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [1])
[junit4] 2> 903471 INFO (zkCallback-927-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 903471 INFO (zkCallback-920-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 903471 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x15323cd060e0005, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 903473 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:42429 42429
[junit4] 2> 903723 INFO (Thread-2255) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:42429 42429
[junit4] 2> 903725 WARN (Thread-2255) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 4 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 4 /solr/clusterstate.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 4 /solr/live_nodes
[junit4] 2> 4 /solr/collections
[junit4] 2>
[junit4] 2> 903725 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.SolrTestCaseJ4 ###Ending testDoubleAssignment
[junit4] 2> 903725 INFO
(TEST-OverseerTest.testDoubleAssignment-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.Overseer Overseer
(id=95459380581761028-127.0.0.1:42429_solr-n_0000000000) closing
[junit4] 2> 903725 INFO
(OverseerStateUpdate-95459380581761028-127.0.0.1:42429_solr-n_0000000000) [
] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:42429_solr
[junit4] 2> 903727 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer
could not read the data
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:353)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:350)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:350)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:308)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:267)
[junit4] 2> 903728 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testShardLeaderChange
[junit4] 2> 903728 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 903729 INFO (Thread-2256) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 903729 INFO (Thread-2256) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 903829 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ZkTestServer start zk server on port:53364
[junit4] 2> 903829 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 903829 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 903831 INFO (zkCallback-928-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@697f29d6
name:ZooKeeperConnection Watcher:127.0.0.1:53364/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 903831 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 903831 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 903831 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 903832 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 903833 INFO (zkCallback-929-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@5785672e
name:ZooKeeperConnection Watcher:127.0.0.1:53364 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 903833 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 903833 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 903834 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 903834 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 903835 INFO (zkCallback-930-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@71bea01c
name:ZooKeeperConnection Watcher:127.0.0.1:53364 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 903835 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 903835 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 903835 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 903838 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 903839 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /collections
[junit4] 2> 903840 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 903841 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 903842 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 903844 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 903844 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient Using
default ZkCredentialsProvider
[junit4] 2> 903844 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 903845 INFO (Thread-2257) [ ] o.a.s.c.c.ConnectionManager
Waiting for client to connect to ZooKeeper
[junit4] 2> 903845 INFO (zkCallback-931-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@722236c0
name:ZooKeeperConnection Watcher:127.0.0.1:53364/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 903845 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 903845 INFO (zkCallback-932-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@67bdd822
name:ZooKeeperConnection Watcher:127.0.0.1:53364/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 903845 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 903845 INFO (Thread-2257) [ ] o.a.s.c.c.ConnectionManager
Client is connected to ZooKeeper
[junit4] 2> 903845 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient Using
default ZkACLProvider
[junit4] 2> 903845 INFO (Thread-2257) [ ] o.a.s.u.UpdateShardHandler
Creating UpdateShardHandler HTTP client with params:
socketTimeout=600000&connTimeout=60000&retry=true
[junit4] 2> 903846 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient
makePath: /overseer_elect
[junit4] 2> 903846 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 903847 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient
makePath: /overseer_elect/election
[junit4] 2> 903848 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0)
[junit4] 2> 903848 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /live_nodes/node1
[junit4] 2> 903848 INFO (Thread-2257) [ ] o.a.s.c.Overseer Overseer
(id=null) closing
[junit4] 2> 903849 INFO (Thread-2257) [ ] o.a.s.c.LeaderElector Joined
leadership election with path:
/overseer_elect/election/95459380649918468-127.0.0.1:53364_solr-n_0000000000
[junit4] 2> 903849 INFO (Thread-2257) [ ]
o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:53364_solr
[junit4] 2> 903849 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient
makePath: /overseer_elect/leader
[junit4] 2> 903850 INFO (zkCallback-931-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [0])
[junit4] 2> 903850 INFO (zkCallback-931-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 903851 INFO (Thread-2257) [ ] o.a.s.c.Overseer Overseer
(id=95459380649918468-127.0.0.1:53364_solr-n_0000000000) starting
[junit4] 2> 903851 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /overseer/queue
[junit4] 2> 903852 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient
makePath: /overseer/queue
[junit4] 2> 903853 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient
makePath: /overseer/queue-work
[junit4] 2> 903854 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient
makePath: /overseer/collection-map-failure
[junit4] 2> 903856 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient
makePath: /overseer/collection-map-running
[junit4] 2> 903857 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient
makePath: /overseer/collection-map-completed
[junit4] 2> 903859 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient
makePath: /overseer/collection-queue-work
[junit4] 2> 903861 INFO (Thread-2257) [ ]
o.a.s.c.OverseerAutoReplicaFailoverThread Starting
OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 903861 INFO
(OverseerCollectionConfigSetProcessor-95459380649918468-127.0.0.1:53364_solr-n_0000000000)
[ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer
operations
[junit4] 2> 903862 INFO (Thread-2257) [ ] o.a.s.c.OverseerTest Killing
overseer.
[junit4] 2> 903862 INFO
(OverseerStateUpdate-95459380649918468-127.0.0.1:53364_solr-n_0000000000) [
] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 903862 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient Using
default ZkCredentialsProvider
[junit4] 2> 903862 ERROR
(OverseerCollectionConfigSetProcessor-95459380649918468-127.0.0.1:53364_solr-n_0000000000)
[ ] o.a.s.c.OverseerTaskProcessor
:org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode
= Session expired for /overseer/collection-queue-work
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:336)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:333)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:333)
[junit4] 2> at
org.apache.solr.cloud.DistributedQueue.fetchZkChildren(DistributedQueue.java:309)
[junit4] 2> at
org.apache.solr.cloud.OverseerTaskQueue.getTailId(OverseerTaskQueue.java:273)
[junit4] 2> at
org.apache.solr.cloud.OverseerTaskProcessor.run(OverseerTaskProcessor.java:147)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 903862 ERROR
(OverseerCollectionConfigSetProcessor-95459380649918468-127.0.0.1:53364_solr-n_0000000000)
[ ] o.a.s.c.OverseerTaskProcessor Unable to prioritize overseer
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /roles.json
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:319)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:316)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:316)
[junit4] 2> at
org.apache.solr.cloud.OverseerNodePrioritizer.prioritizeOverseerNodes(OverseerNodePrioritizer.java:60)
[junit4] 2> at
org.apache.solr.cloud.OverseerTaskProcessor.run(OverseerTaskProcessor.java:162)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 903862 INFO (Thread-2257) [ ] o.a.s.c.c.ConnectionManager
Waiting for client to connect to ZooKeeper
[junit4] 2> 903863 INFO
(OverseerCollectionConfigSetProcessor-95459380649918468-127.0.0.1:53364_solr-n_0000000000)
[ ] o.a.s.c.OverseerTaskProcessor
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:353)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:350)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:350)
[junit4] 2> at
org.apache.solr.cloud.OverseerTaskProcessor.amILeader(OverseerTaskProcessor.java:358)
[junit4] 2> at
org.apache.solr.cloud.OverseerTaskProcessor.run(OverseerTaskProcessor.java:175)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 903863 INFO
(OverseerCollectionConfigSetProcessor-95459380649918468-127.0.0.1:53364_solr-n_0000000000)
[ ] o.a.s.c.OverseerTaskProcessor According to ZK I
(id=95459380649918468-127.0.0.1:53364_solr-n_0000000000) am no longer a leader.
[junit4] 2> 903865 INFO (zkCallback-935-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@568ca181
name:ZooKeeperConnection Watcher:127.0.0.1:53364/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 903865 INFO (Thread-2257) [ ] o.a.s.c.c.ConnectionManager
Client is connected to ZooKeeper
[junit4] 2> 903865 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient Using
default ZkACLProvider
[junit4] 2> 903865 INFO (Thread-2257) [ ] o.a.s.c.Overseer Overseer
(id=95459380649918468-127.0.0.1:53364_solr-n_0000000000) closing
[junit4] 2> 903865 INFO (Thread-2257) [ ] o.a.s.u.UpdateShardHandler
Creating UpdateShardHandler HTTP client with params:
socketTimeout=600000&connTimeout=60000&retry=true
[junit4] 2> 903865 INFO
(OverseerStateUpdate-95459380649918468-127.0.0.1:53364_solr-n_0000000000) [
] o.a.s.c.Overseer According to ZK I
(id=95459380649918468-127.0.0.1:53364_solr-n_0000000000) am no longer a leader.
[junit4] 2> 903865 INFO
(OverseerStateUpdate-95459380649918468-127.0.0.1:53364_solr-n_0000000000) [
] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:53364_solr
[junit4] 2> 903867 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer
could not read the data
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:353)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:350)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:350)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:308)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:267)
[junit4] 2> 903867 INFO (Thread-2257) [ ] o.a.s.c.Overseer Overseer
(id=null) closing
[junit4] 2> 903868 INFO (Thread-2257) [ ] o.a.s.c.LeaderElector Joined
leadership election with path:
/overseer_elect/election/95459380649918469-127.0.0.1:53364_solr-n_0000000001
[junit4] 2> 903868 INFO (Thread-2257) [ ]
o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:53364_solr
[junit4] 2> 903868 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient
makePath: /overseer_elect/leader
[junit4] 2> 903869 INFO (Thread-2257) [ ] o.a.s.c.Overseer Overseer
(id=95459380649918469-127.0.0.1:53364_solr-n_0000000001) starting
[junit4] 2> 903874 INFO (Thread-2257) [ ]
o.a.s.c.OverseerAutoReplicaFailoverThread Starting
OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 903874 INFO
(OverseerCollectionConfigSetProcessor-95459380649918469-127.0.0.1:53364_solr-n_0000000001)
[ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer
operations
[junit4] 2> 903876 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 903877 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 903878 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 903879 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"} current state version: 0
[junit4] 2> 903879 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 903879 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.o.ClusterStateMutator building a new cName: collection1
[junit4] 2> 903879 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 903880 INFO (zkCallback-935-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 903880 INFO (zkCallback-931-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 904352 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 904354 INFO (zkCallback-931-thread-1) [ ]
o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/collections], has occurred - updating...
[junit4] 2> 904354 INFO (zkCallback-935-thread-1) [ ]
o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/collections], has occurred - updating...
[junit4] 2> 904356 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.LeaderElector Joined leadership election with path:
/collections/collection1/leader_elect/shard1/election/95459380649918467-node1_core1-n_0000000000
[junit4] 2> 904357 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard1
[junit4] 2> 904359 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node
/collections/collection1/leaders/shard1/leader after winning as
/collections/collection1/leader_elect/shard1/election/95459380649918467-node1_core1-n_0000000000
[junit4] 2> 904361 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"http://node1/solr/",
[junit4] 2> "core":"core1",
[junit4] 2> "state":"active"} current state version: 1
[junit4] 2> 904361 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ElectionContext Canceling election
/collections/collection1/leader_elect/shard1/election/95459380649918467-node1_core1-n_0000000000
[junit4] 2> 904361 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ShardLeaderElectionContextBase Removing leader registration node on
cancel: /collections/collection1/leaders/shard1/leader 1
[junit4] 2> 904362 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 904362 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"} current state version: 1
[junit4] 2> 904362 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 904363 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered
[junit4] 2> 904364 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.LeaderElector Joined leadership election with path:
/collections/collection1/leader_elect/shard1/election/95459380649918467-node1_core1-n_0000000001
[junit4] 2> 904365 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node
/collections/collection1/leaders/shard1/leader after winning as
/collections/collection1/leader_elect/shard1/election/95459380649918467-node1_core1-n_0000000001
[junit4] 2> 904366 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 904367 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 904369 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"http://node1/solr/",
[junit4] 2> "core":"core1",
[junit4] 2> "state":"active"} current state version: 1
[junit4] 2> 904369 INFO (zkCallback-938-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@5254c977
name:ZooKeeperConnection Watcher:127.0.0.1:53364/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 904369 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 904369 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 904370 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 904372 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 904372 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /live_nodes/node2
[junit4] 2> 904373 INFO (zkCallback-935-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [1])
[junit4] 2> 904373 INFO (zkCallback-938-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [1])
[junit4] 2> 904373 INFO (zkCallback-931-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [1])
[junit4] 2> 904374 INFO (zkCallback-931-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 904374 INFO (zkCallback-935-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 904374 INFO (zkCallback-938-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 904375 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ElectionContext Canceling election
/collections/collection1/leader_elect/shard1/election/95459380649918467-node1_core1-n_0000000001
[junit4] 2> 904376 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ShardLeaderElectionContextBase Removing leader registration node on
cancel: /collections/collection1/leaders/shard1/leader 2
[junit4] 2> 904376 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"} current state version: 1
[junit4] 2> 904376 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 904376 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 904376 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered
[junit4] 2> 904379 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.LeaderElector Joined leadership election with path:
/collections/collection1/leader_elect/shard1/election/95459380649918467-node1_core1-n_0000000002
[junit4] 2> 904379 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node
/collections/collection1/leaders/shard1/leader after winning as
/collections/collection1/leader_elect/shard1/election/95459380649918467-node1_core1-n_0000000002
[junit4] 2> 904381 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 904382 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"http://node1/solr/",
[junit4] 2> "core":"core1",
[junit4] 2> "state":"active"} current state version: 1
[junit4] 2> 904382 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 904483 INFO (zkCallback-935-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [2])
[junit4] 2> 904484 INFO (zkCallback-928-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [2])
[junit4] 2> 904484 INFO (zkCallback-938-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [2])
[junit4] 2> 904484 INFO (zkCallback-931-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [2])
[junit4] 2> 904584 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (2)
[junit4] 2> 904586 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"} current state version: 2
[junit4] 2> 904586 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 904586 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.o.ReplicaMutator Collection already exists with numShards=1
[junit4] 2> 904586 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 904688 INFO (zkCallback-938-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [2])
[junit4] 2> 904689 INFO (zkCallback-931-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [2])
[junit4] 2> 904689 INFO (zkCallback-935-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [2])
[junit4] 2> 904689 INFO (zkCallback-928-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [2])
[junit4] 2> 905085 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 905088 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.LeaderElector Joined leadership election with path:
/collections/collection1/leader_elect/shard1/election/95459380649918470-node2_core4-n_0000000003
[junit4] 2> 905089 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.LeaderElector Watching path
/collections/collection1/leader_elect/shard1/election/95459380649918467-node1_core1-n_0000000002
to know if I could be the leader
[junit4] 2> 905089 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ElectionContext Canceling election
/collections/collection1/leader_elect/shard1/election/95459380649918467-node1_core1-n_0000000002
[junit4] 2> 905091 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ShardLeaderElectionContextBase Removing leader registration node on
cancel: /collections/collection1/leaders/shard1/leader 3
[junit4] 2> 905092 INFO (zkCallback-938-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node
/collections/collection1/leaders/shard1/leader after winning as
/collections/collection1/leader_elect/shard1/election/95459380649918470-node2_core4-n_0000000003
[junit4] 2> 905092 INFO (zkCallback-935-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [2])
[junit4] 2> 905092 INFO (zkCallback-931-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [2])
[junit4] 2> 905093 INFO (zkCallback-928-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [2])
[junit4] 2> 905093 INFO (zkCallback-938-thread-2) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [2])
[junit4] 2> 905093 INFO (zkCallback-935-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 905093 INFO (zkCallback-928-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 905093 INFO (zkCallback-938-thread-2) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 905095 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"http://node2/solr/",
[junit4] 2> "core":"core4",
[junit4] 2> "state":"active"} current state version: 3
[junit4] 2> 905197 INFO (zkCallback-935-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 905197 INFO (zkCallback-928-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 905197 INFO (zkCallback-938-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 906593 WARN (zkCallback-931-thread-1) [ ]
o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK:
[KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 906594 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (1)
[junit4] 2> 906594 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 906594 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 906595 INFO (zkCallback-939-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@698dbcc1
name:ZooKeeperConnection Watcher:127.0.0.1:53364/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 906595 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 906596 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 906597 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 906598 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 906599 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath: /live_nodes/node1
[junit4] 2> 906600 INFO (zkCallback-939-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [1])
[junit4] 2> 906600 INFO (zkCallback-928-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [1])
[junit4] 2> 906600 INFO (zkCallback-935-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [1])
[junit4] 2> 906600 INFO (zkCallback-938-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [1])
[junit4] 2> 906600 INFO (zkCallback-928-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 906601 INFO (zkCallback-938-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 906601 INFO (zkCallback-939-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 906601 INFO (zkCallback-935-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 906602 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 906603 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"} current state version: 4
[junit4] 2> 906607 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 906607 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered
[junit4] 2> 906609 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.LeaderElector Joined leadership election with path:
/collections/collection1/leader_elect/shard1/election/95459380649918471-node1_core1-n_0000000004
[junit4] 2> 906610 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.LeaderElector Watching path
/collections/collection1/leader_elect/shard1/election/95459380649918470-node2_core4-n_0000000003
to know if I could be the leader
[junit4] 2> 906610 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ElectionContext Canceling election
/collections/collection1/leader_elect/shard1/election/95459380649918470-node2_core4-n_0000000003
[junit4] 2> 906610 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ShardLeaderElectionContextBase Removing leader registration node on
cancel: /collections/collection1/leaders/shard1/leader 4
[junit4] 2> 906613 INFO (zkCallback-938-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [2])
[junit4] 2> 906613 INFO (zkCallback-928-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [2])
[junit4] 2> 906613 INFO (zkCallback-939-thread-2) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [2])
[junit4] 2> 906613 INFO (zkCallback-935-thread-1) [ ]
o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected
type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live
nodes size: [2])
[junit4] 2> 906613 INFO (zkCallback-939-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node
/collections/collection1/leaders/shard1/leader after winning as
/collections/collection1/leader_elect/shard1/election/95459380649918471-node1_core1-n_0000000004
[junit4] 2> 906614 INFO (zkCallback-928-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 906614 INFO (zkCallback-935-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 906614 INFO (zkCallback-939-thread-2) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 906618 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"http://node1/solr/",
[junit4] 2> "core":"core1",
[junit4] 2> "state":"active"} current state version: 4
[junit4] 2> 906677 INFO (Thread-2257) [ ] o.a.s.c.OverseerTest Killing
overseer.
[junit4] 2> 906678 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient Using
default ZkCredentialsProvider
[junit4] 2> 906679 INFO (Thread-2257) [ ] o.a.s.c.c.ConnectionManager
Waiting for client to connect to ZooKeeper
[junit4] 2> 906680 INFO (zkCallback-940-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@32053025
name:ZooKeeperConnection Watcher:127.0.0.1:53364/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 906680 INFO (Thread-2257) [ ] o.a.s.c.c.ConnectionManager
Client is connected to ZooKeeper
[junit4] 2> 906680 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient Using
default ZkACLProvider
[junit4] 2> 906680 INFO (Thread-2257) [ ] o.a.s.c.Overseer Overseer
(id=95459380649918469-127.0.0.1:53364_solr-n_0000000001) closing
[junit4] 2> 906680 INFO (Thread-2257) [ ] o.a.s.u.UpdateShardHandler
Creating UpdateShardHandler HTTP client with params:
socketTimeout=600000&connTimeout=60000&retry=true
[junit4] 2> 906681 INFO
(OverseerStateUpdate-95459380649918469-127.0.0.1:53364_solr-n_0000000001) [
] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:53364_solr
[junit4] 2> 906689 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer
could not read the data
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:353)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:350)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:350)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:308)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:267)
[junit4] 2> 906691 INFO (Thread-2257) [ ] o.a.s.c.Overseer Overseer
(id=null) closing
[junit4] 2> 906691 INFO (Thread-2257) [ ] o.a.s.c.LeaderElector Joined
leadership election with path:
/overseer_elect/election/95459380649918472-127.0.0.1:53364_solr-n_0000000002
[junit4] 2> 906691 INFO (Thread-2257) [ ]
o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:53364_solr
[junit4] 2> 906691 INFO (Thread-2257) [ ] o.a.s.c.c.SolrZkClient
makePath: /overseer_elect/leader
[junit4] 2> 906692 INFO (Thread-2257) [ ] o.a.s.c.Overseer Overseer
(id=95459380649918472-127.0.0.1:53364_solr-n_0000000002) starting
[junit4] 2> 906697 INFO (Thread-2257) [ ]
o.a.s.c.OverseerAutoReplicaFailoverThread Starting
OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 906698 INFO
(OverseerCollectionConfigSetProcessor-95459380649918472-127.0.0.1:53364_solr-n_0000000002)
[ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer
operations
[junit4] 2> 906698 INFO
(OverseerStateUpdate-95459380649918472-127.0.0.1:53364_solr-n_0000000002) [
] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 906698 INFO
(OverseerStateUpdate-95459380649918472-127.0.0.1:53364_solr-n_0000000002) [
] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 906699 INFO
(OverseerStateUpdate-95459380649918472-127.0.0.1:53364_solr-n_0000000002) [
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 906701 INFO
(OverseerStateUpdate-95459380649918472-127.0.0.1:53364_solr-n_0000000002) [
] o.a.s.c.Overseer processMessage: workQueueSize: 2, message = {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 906701 INFO
(OverseerStateUpdate-95459380649918472-127.0.0.1:53364_solr-n_0000000002) [
] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 906701 INFO
(OverseerStateUpdate-95459380649918472-127.0.0.1:53364_solr-n_0000000002) [
] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered
[junit4] 2> 906701 INFO (zkCallback-928-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 906701 INFO (zkCallback-939-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 906702 INFO (zkCallback-940-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 906703 INFO
(OverseerStateUpdate-95459380649918472-127.0.0.1:53364_solr-n_0000000002) [
] o.a.s.c.Overseer processMessage: workQueueSize: 2, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"http://node1/solr/",
[junit4] 2> "core":"core1",
[junit4] 2> "state":"active"}
[junit4] 2> 906704 INFO (zkCallback-939-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 906704 INFO (zkCallback-928-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 906704 INFO (zkCallback-940-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [1])
[junit4] 2> 908113 WARN (zkCallback-938-thread-1) [ ]
o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK:
[KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 908114 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ElectionContext Canceling election
/collections/collection1/leader_elect/shard1/election/95459380649918471-node1_core1-n_0000000004
[junit4] 2> 908115 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ShardLeaderElectionContextBase Removing leader registration node on
cancel: /collections/collection1/leaders/shard1/leader 5
[junit4] 2> 908115 INFO
(OverseerStateUpdate-95459380649918472-127.0.0.1:53364_solr-n_0000000002) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"} current state version: 6
[junit4] 2> 908116 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 908116 INFO
(OverseerStateUpdate-95459380649918472-127.0.0.1:53364_solr-n_0000000002) [
] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 908116 INFO
(OverseerStateUpdate-95459380649918472-127.0.0.1:53364_solr-n_0000000002) [
] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered
[junit4] 2> 908122 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.LeaderElector Joined leadership election with path:
/collections/collection1/leader_elect/shard1/election/95459380649918471-node1_core1-n_0000000005
[junit4] 2> 908122 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node
/collections/collection1/leaders/shard1/leader after winning as
/collections/collection1/leader_elect/shard1/election/95459380649918471-node1_core1-n_0000000005
[junit4] 2> 908124 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 908125 INFO
(OverseerStateUpdate-95459380649918472-127.0.0.1:53364_solr-n_0000000002) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"http://node1/solr/",
[junit4] 2> "core":"core1",
[junit4] 2> "state":"active"} current state version: 6
[junit4] 2> 908125 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 908126 INFO (zkCallback-943-thread-1) [ ]
o.a.s.c.c.ConnectionManager Watcher
org.apache.solr.common.cloud.ConnectionManager@5ab88d94
name:ZooKeeperConnection Watcher:127.0.0.1:53364/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 908126 INFO
(TEST-OverseerTest.testShardLeaderChange-seed#[31D689C6D24391D6
[...truncated too long message...]
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json], has occurred - updating... (live nodes size: [0])
[junit4] 2> 958509 INFO (zkCallback-1055-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [0])
[junit4] 2> 958555 INFO
(OverseerStateUpdate-95459384210489347-127.0.0.1:37502_solr-n_0000000000) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"deletecore",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core_node_name":"core_node3"} current state version: 3
[junit4] 2> 958657 INFO (zkCallback-1054-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [0])
[junit4] 2> 958657 INFO (zkCallback-1055-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [0])
[junit4] 2> 958706 INFO
(OverseerStateUpdate-95459384210489347-127.0.0.1:37502_solr-n_0000000000) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"deletecore",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core_node_name":"core_node2"} current state version: 4
[junit4] 2> 958808 INFO (zkCallback-1054-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [0])
[junit4] 2> 958808 INFO (zkCallback-1055-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [0])
[junit4] 2> 958857 INFO
(OverseerStateUpdate-95459384210489347-127.0.0.1:37502_solr-n_0000000000) [
] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"deletecore",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core_node_name":"core_node1"} current state version: 5
[junit4] 2> 958959 INFO (zkCallback-1054-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [0])
[junit4] 2> 958959 INFO (zkCallback-1055-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred
- updating... (live nodes size: [0])
[junit4] 2> 959008 INFO
(TEST-OverseerTest.testRemovalOfLastReplica-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:37502 37502
[junit4] 2> 959829 INFO (Thread-2267) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:37502 37502
[junit4] 2> 959831 WARN (Thread-2267) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/clusterstate.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/live_nodes
[junit4] 2> 2 /solr/collections
[junit4] 2>
[junit4] 2> 959831 INFO
(TEST-OverseerTest.testRemovalOfLastReplica-seed#[31D689C6D24391D6]) [ ]
o.a.s.SolrTestCaseJ4 ###Ending testRemovalOfLastReplica
[junit4] 2> 959831 INFO
(TEST-OverseerTest.testRemovalOfLastReplica-seed#[31D689C6D24391D6]) [ ]
o.a.s.c.Overseer Overseer
(id=95459384210489347-127.0.0.1:37502_solr-n_0000000000) closing
[junit4] 2> 959831 INFO
(OverseerStateUpdate-95459384210489347-127.0.0.1:37502_solr-n_0000000000) [
] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:37502_solr
[junit4] 2> 959831 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer
could not read the data
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:353)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:350)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:350)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:308)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:267)
[junit4] 2> 962832 INFO
(SUITE-OverseerTest-seed#[31D689C6D24391D6]-worker) [ ] o.a.s.SolrTestCaseJ4
###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-trunk-Java8/solr/build/solr-core/test/J2/temp/solr.cloud.OverseerTest_31D689C6D24391D6-001
[junit4] 2> NOTE: test params are:
codec=FastDecompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST_DECOMPRESSION,
chunkSize=21000, maxDocsPerChunk=8, blockSize=132),
termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST_DECOMPRESSION,
chunkSize=21000, blockSize=132)), sim=ClassicSimilarity, locale=hi-IN,
timezone=America/Ojinaga
[junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation
1.8.0_66 (64-bit)/cpus=4,threads=1,free=82852536,total=527433728
[junit4] 2> NOTE: All tests run in this JVM: [CurrencyFieldXmlFileTest,
BinaryUpdateRequestHandlerTest, DirectSolrConnectionTest, NoCacheHeaderTest,
QueryResultKeyTest, SampleTest, TestSearcherReuse, JavabinLoaderTest,
TestConfigSetsAPIExclusivity, XmlUpdateRequestHandlerTest, SliceStateTest,
TestReversedWildcardFilterFactory, TestLeaderElectionZkExpiry,
TestSizeLimitedDistributedMap, TestZkChroot, TestExtendedDismaxParser,
UnloadDistributedZkTest, SuggesterTest, TriLevelCompositeIdRoutingTest,
TestMinMaxOnMultiValuedField, CollectionStateFormat2Test, TestReload,
InfoHandlerTest, TestPHPSerializedResponseWriter, HdfsThreadLeakTest,
ClusterStateTest, TestSuggestSpellingConverter, QueryParsingTest,
BasicDistributedZk2Test, DirectUpdateHandlerTest, SolrXmlInZkTest,
HdfsRecoveryZkTest, TestSort, TestSolrQueryResponse, UpdateParamsTest,
TermVectorComponentDistributedTest, TestBlendedInfixSuggestions,
SharedFSAutoReplicaFailoverUtilsTest, SuggesterTSTTest, TestFieldResource,
RecoveryAfterSoftCommitTest, TestDistributedMissingSort, TestMissingGroups,
TestSolrQueryParser, ResponseHeaderTest, AtomicUpdatesTest, TestUtils,
TestSolr4Spatial2, TestRemoveLastDynamicCopyField, TestWriterPerf,
HdfsWriteToMultipleCollectionsTest, TestTestInjection, TestRecovery,
TestSolrConfigHandler, DistributedFacetPivotWhiteBoxTest, StatsComponentTest,
ShowFileRequestHandlerTest, HttpPartitionTest, CleanupOldIndexTest,
TestClassNameShortening, SuggesterWFSTTest, RestartWhileUpdatingTest,
DistributedQueueTest, ChangedSchemaMergeTest, PrimitiveFieldTypeTest,
BlockJoinFacetSimpleTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest,
TestCustomDocTransformer, TestManagedResourceStorage,
TestImplicitCoreProperties, TestUseDocValuesAsStored, BadComponentTest,
LukeRequestHandlerTest, TestSolrDeletionPolicy1,
DistributedSuggestComponentTest, SuggestComponentContextFilterQueryTest,
CustomCollectionTest, OverseerRolesTest, TestSQLHandler, TestJmxMonitoredMap,
TestJettySolrRunner, RequestHandlersTest, TestIndexingPerformance,
SimpleFacetsTest, PluginInfoTest, TestPKIAuthenticationPlugin,
FieldMutatingUpdateProcessorTest, BufferStoreTest,
TestSolrQueryParserDefaultOperatorResource, RequestLoggingTest,
TestConfigSetProperties, DeleteReplicaTest, TestPerFieldSimilarity,
SyncSliceTest, OverseerTest]
[junit4] Completed [253/581 (1!)] on J2 in 60.16s, 13 tests, 1 failure, 1
skipped <<< FAILURES!
[...truncated 1075 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-trunk-Java8/build.xml:740:
The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-trunk-Java8/build.xml:684:
The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-trunk-Java8/build.xml:59:
The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-trunk-Java8/solr/build.xml:233:
The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-trunk-Java8/solr/common-build.xml:524:
The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-trunk-Java8/lucene/common-build.xml:1457:
The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-trunk-Java8/lucene/common-build.xml:1014:
There were test failures: 581 suites (8 ignored), 2349 tests, 1 failure, 87
ignored (71 assumptions) [seed: 31D689C6D24391D6]
Total time: 59 minutes 9 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]