[
https://issues.apache.org/jira/browse/SOLR-5473?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Timothy Potter updated SOLR-5473:
---------------------------------
Attachment: ec2-23-20-119-52_solr.log
ec2-50-16-38-73_solr.log
I'm seeing a race condition when creating new external collections where the
leader=true flag is getting lost on some of the shards. I'm calling this a race
condition because it does not happen all the time, but is fairly consistent in
my cluster. I'm trying to create an external collection with 4 shards and RF=3
in a 4-node cluster using this patch, e.g.
http://HOST:PORT/solr/admin/collections?action=CREATE&name=tj4&replicationFactor=3&numShards=4&collection.configName=cloud&maxShardsPerNode=3&external=true
After running this, the collection ended up being invalid because shard2 does
not have a leader.
Here are some interesting log messages from a few of the servers involved in
the leader election of shard2.
btw - those nodes are dead now, so I didn't bother obfuscating hostnames
>>>> ec2-50-16-38-73 NODE THAT THINKS IT IS THE LEADER <<<<
2014-03-03 20:26:17,414 [qtp336293446-23] INFO
solr.cloud.ShardLeaderElectionContext - I may be the new leader - try and sync
2014-03-03 20:26:17,414 [qtp336293446-23] INFO solr.cloud.SyncStrategy - Sync
replicas to
http://ec2-50-16-38-73.compute-1.amazonaws.com:8984/solr/tj4_shard2_replica3/
2014-03-03 20:26:17,414 [qtp336293446-23] INFO solr.update.PeerSync -
PeerSync: core=tj4_shard2_replica3
url=http://ec2-50-16-38-73.compute-1.amazonaws.com:8984/solr START
replicas=[http://ec2-23-20-119-52.compute-1.amazonaws.com:8984/solr/tj4_shard2_replica2/,
http://ec2-54-237-76-40.compute-1.amazonaws.com:8984/solr/tj4_shard2_replica1/]
nUpdates=100
2014-03-03 20:26:17,415 [qtp336293446-23] INFO solr.update.PeerSync -
PeerSync: core=tj4_shard2_replica3
url=http://ec2-50-16-38-73.compute-1.amazonaws.com:8984/solr DONE. We have no
versions. sync failed.
2014-03-03 20:26:17,415 [qtp336293446-23] INFO solr.cloud.SyncStrategy -
Leader's attempt to sync with shard failed, moving to the next candidate
2014-03-03 20:26:17,415 [qtp336293446-23] INFO
solr.cloud.ShardLeaderElectionContext - We failed sync, but we have no
versions - we can't sync in that case - we were active before, so become leader
anyway
2014-03-03 20:26:17,415 [qtp336293446-23] INFO
solr.cloud.ShardLeaderElectionContext - I am the new leader:
http://ec2-50-16-38-73.compute-1.amazonaws.com:8984/solr/tj4_shard2_replica3/
shard2
2014-03-03 20:26:17,415 [qtp336293446-23] INFO common.cloud.SolrZkClient -
makePath: /collections/tj4/leaders/shard2
2014-03-03 20:26:17,423 [qtp336293446-23] INFO
solr.cloud.ShardLeaderElectionContextBase - For shard2, offering ZkNodeProps
JSON: {
"operation":"leader",
"shard":"shard2",
"collection":"tj4",
"base_url":"http://ec2-50-16-38-73.compute-1.amazonaws.com:8984/solr";,
"core":"tj4_shard2_replica3",
"state":"active"}; current queue size is: 1
2014-03-03 20:26:17,426 [qtp336293446-23] INFO
solr.cloud.ShardLeaderElectionContext - runLeaderProcess(false) succeeded for
shard2
2014-03-03 20:26:17,441 [main-EventThread] INFO common.cloud.ZkStateReader -
A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/tj4/state via watch on path /collections/tj4/state, has
occurred - updating...
2014-03-03 20:26:17,444 [main-EventThread] INFO common.cloud.ZkStateReader -
Updating data for tj4
2014-03-03 20:26:17,444 [main-EventThread] INFO common.cloud.ZkStateReader -
A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
2014-03-03 20:26:17,469 [main-EventThread] INFO common.cloud.ZkStateReader -
A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/tj4/state via watch on path /collections/tj4/state, has
occurred - updating...
2014-03-03 20:26:17,471 [main-EventThread] INFO common.cloud.ZkStateReader -
Updating data for tj4
2014-03-03 20:26:17,471 [main-EventThread] INFO common.cloud.ZkStateReader -
A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
2014-03-03 20:26:17,476 [qtp336293446-23] INFO solr.cloud.ZkController - We
are
http://ec2-50-16-38-73.compute-1.amazonaws.com:8984/solr/tj4_shard2_replica3/
and leader is
http://ec2-50-16-38-73.compute-1.amazonaws.com:8984/solr/tj4_shard2_replica3/
2014-03-03 20:26:17,476 [qtp336293446-23] INFO solr.cloud.ZkController - No
LogReplay needed for core=tj4_shard2_replica3
baseURL=http://ec2-50-16-38-73.compute-1.amazonaws.com:8984/solr
2014-03-03 20:26:17,476 [qtp336293446-23] INFO solr.cloud.ZkController - I am
the leader, no recovery necessary
2014-03-03 20:26:17,476 [qtp336293446-23] INFO solr.cloud.ZkController -
publishing core=tj4_shard2_replica3 state=active
>>>>> OVER ON THE OVERSEER NODE ec2-23-20-119-52 <<<<<<
2014-03-03 20:26:17,008 [Thread-21] INFO solr.cloud.Overseer - Processing
leader operation for shard2; coreName=tj4_shard2_replica3
2014-03-03 20:26:17,008 [Thread-21] INFO solr.cloud.Overseer - Applying
leader change for shard2 for tj4;
leaderUrl=http://ec2-50-16-38-73.compute-1.amazonaws.com:8984/solr/tj4_shard2_replica3/
2014-03-03 20:26:17,008 [Thread-21] INFO solr.cloud.Overseer - Set replica
core_node7 as the leader for shard shard2 for collection tj4;
leaderUrl=http://ec2-50-16-38-73.compute-1.amazonaws.com:8984/solr/tj4_shard2_replica3/
2014-03-03 20:26:17,008 [Thread-21] INFO solr.cloud.Overseer - updateNodes:
put /collections/tj4/state
2014-03-03 20:26:17,008 [Thread-21] INFO solr.cloud.Overseer - Created new
ClusterState for shard2 for collection tj4: live
nodes:[ec2-54-198-254-111.compute-1.amazonaws.com:8984_solr,
ec2-54-237-76-40.compute-1.amazonaws.com:8984_solr,
ec2-50-16-38-73.compute-1.amazonaws.com:8984_solr,
ec2-23-20-119-52.compute-1.amazonaws.com:8984_solr] collections:{}
2014-03-03 20:26:17,008 [Thread-21] INFO solr.cloud.Overseer - After
processsing leader, clusterState: live
nodes:[ec2-54-198-254-111.compute-1.amazonaws.com:8984_solr,
ec2-54-237-76-40.compute-1.amazonaws.com:8984_solr,
ec2-50-16-38-73.compute-1.amazonaws.com:8984_solr,
ec2-23-20-119-52.compute-1.amazonaws.com:8984_solr] collections:{}
2014-03-03 20:26:17,013 [Thread-21] INFO solr.cloud.Overseer - updateNodes
not empty: 1
2014-03-03 20:26:17,014 [Thread-21] INFO solr.cloud.Overseer - going to
update_collection live nodes:[] collections:{tj4=DocCollection(tj4)={
"shards":{
"shard1":{
....
"shard2":{
"range":"c0000000-ffffffff",
"state":"active",
"replicas":{
"core_node1":{
"state":"down",
"base_url":"http://ec2-23-20-119-52.compute-1.amazonaws.com:8984/solr";,
"core":"tj4_shard2_replica2",
"node_name":"ec2-23-20-119-52.compute-1.amazonaws.com:8984_solr"},
"core_node5":{
"state":"down",
"base_url":"http://ec2-54-237-76-40.compute-1.amazonaws.com:8984/solr";,
"core":"tj4_shard2_replica1",
"node_name":"ec2-54-237-76-40.compute-1.amazonaws.com:8984_solr"},
"core_node7":{
"state":"down",
"base_url":"http://ec2-50-16-38-73.compute-1.amazonaws.com:8984/solr";,
"core":"tj4_shard2_replica3",
"node_name":"ec2-50-16-38-73.compute-1.amazonaws.com:8984_solr",
"leader":"true"}}}, <====== SHARD #2's LEADER!!!
NOTE: JSON trimmed for brevity
Notice that the correct shard is marked as the leader in the state.json znode
for this collection, this is goodness and expected
However, sometime very soon after, which you can see in the attached log
ec2-23-20-119-52_solr.log around lines 28577 - 28637, a new state is published
that has now lost the leader property for shard2.
"shard2":{
"range":"c0000000-ffffffff",
"state":"active",
"replicas":{
"core_node1":{
"state":"down",
"base_url":"http://ec2-23-20-119-52.compute-1.amazonaws.com:8984/solr";,
"core":"tj4_shard2_replica2",
"node_name":"ec2-23-20-119-52.compute-1.amazonaws.com:8984_solr"},
"core_node5":{
"state":"down",
"base_url":"http://ec2-54-237-76-40.compute-1.amazonaws.com:8984/solr";,
"core":"tj4_shard2_replica1",
"node_name":"ec2-54-237-76-40.compute-1.amazonaws.com:8984_solr"},
"core_node7":{
"state":"down",
"base_url":"http://ec2-50-16-38-73.compute-1.amazonaws.com:8984/solr";,
"core":"tj4_shard2_replica3",
"node_name":"ec2-50-16-38-73.compute-1.amazonaws.com:8984_solr"}}},
<====== NO LONGER THE LEADER ?!?
See attached logs for these two servers.
Looks to me like somehow, depending on timing of status updates to collection
state, the leader flag on one or more of the shards can get lost. Again, this
doesn't happen all the time but does happen fairly often in a cluster that is
networked. I haven't been able to get it to happen when running 4-nodes on my
workstation.
> Make one state.json per collection
> ----------------------------------
>
> Key: SOLR-5473
> URL: https://issues.apache.org/jira/browse/SOLR-5473
> Project: Solr
> Issue Type: Sub-task
> Components: SolrCloud
> Reporter: Noble Paul
> Assignee: Noble Paul
> Attachments: SOLR-5473-74.patch, SOLR-5473-74.patch, SOLR-5473.patch,
> SOLR-5473.patch, SOLR-5473.patch, SOLR-5473.patch, SOLR-5473.patch,
> SOLR-5473.patch, SOLR-5473.patch, SOLR-5473.patch, SOLR-5473.patch,
> SOLR-5473.patch, SOLR-5473.patch, SOLR-5473.patch, SOLR-5473.patch,
> SOLR-5473.patch, SOLR-5473.patch, SOLR-5473.patch, SOLR-5473.patch,
> SOLR-5473.patch, ec2-23-20-119-52_solr.log, ec2-50-16-38-73_solr.log
>
>
> As defined in the parent issue, store the states of each collection under
> /collections/collectionname/state.json node
--
This message was sent by Atlassian JIRA
(v6.2#6252)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
