Bug 1162727

Summary: member weirdness when adding/removing nodes
Product: Red Hat Enterprise Linux 7 Reporter: Radek Steiger <rsteiger>
Component: pacemakerAssignee: Andrew Beekhof <abeekhof>
Status: CLOSED ERRATA QA Contact: cluster-qe <cluster-qe>
Severity: urgent Docs Contact:
Priority: urgent    
Version: 7.1CC: cfeist, cluster-maint, cluster-qe, fdinitto, jherrman, jkortus, lmiksik, mjuricek, tlavigne
Target Milestone: rcKeywords: ZStream
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: pacemaker-1.1.13-3.el7 Doc Type: Bug Fix
Doc Text:
Previously, removing and adding cluster nodes in some cases caused conflicting node IDs, which in turn led to certain Pacemaker components terminating unexpectedly. This update overhauls peer cache management to ensure that recycling node IDs is handled correctly, and the described problem thus no longer occurs.
Story Points: ---
Clone Of:
: 1193499 1244101 (view as bug list) Environment:
Last Closed: 2015-11-19 12:12:02 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1193499, 1244101    

Description Radek Steiger 2014-11-11 15:02:03 UTC
> Description of problem:


I'm recently running into a repeating problem when continuously adding/removing cluster nodes.

The issue as seen from pacemaker.log looks like this:

attrd:  warning: crm_find_peer:     Node 'virt-127' and 'virt-131' share the same cluster nodeid: 3 virt-131
attrd:    error: crm_abort:     crm_find_peer: Forked child 20878 to record non-fatal assert at membership.c:394 : member weirdness


I was able to reproduce this multiple times in various different sequences of steps, but here is how did I got to the latest one:

- i'm running a cluster of 7 nodes
- stopped virt-130
- removed node virt-126
- removed node virt-131
- removed node virt-127
- added back node virt-131

The initial node ID distribution:

1    virt-122
2    virt-126
3    virt-127
4    virt-128
5    virt-129
6    virt-130
7    virt-131

The final ID distribution after all additions/removals:

1    virt-122
3    virt-131
4    virt-128
5    virt-129
6    virt-130

As you can see virt-131 has been reassigned an ID previously used by node virt-127. I believe in theory this shouldn't be an issue as the node is long gone, but something in the logs disagrees with me. Here is more context to the log lines above, taken AFTER the final ID distribution:

crmd:     info: pcmk_quorum_notification:      Membership 92: quorum retained (4)
pacemakerd:     info: pcmk_quorum_notification:      Membership 92: quorum retained (4)
crmd:     info: crm_get_peer:  Created entry ad118388-45cd-41f0-9e30-e468433632ba/0x16f6e30 for node virt-131/3 (5 total)
crmd:     info: crm_get_peer:  Node 3 is now known as virt-131
crmd:     info: peer_update_callback:  virt-131 is now (null)
crmd:     info: crm_get_peer:  Node 3 has uuid 3
crmd:   notice: crm_update_peer_state:         pcmk_quorum_notification: Node virt-131[3] - state is now member (was (null))
crmd:     info: peer_update_callback:  virt-131 is now member (was (null))
pacemakerd:     info: crm_get_peer:  Created entry 95269e93-a643-4b65-b0e7-f1d6561e5990/0x1bbfcd0 for node virt-131/3 (5 total)
pacemakerd:     info: crm_get_peer:  Node 3 is now known as virt-131
pacemakerd:     info: crm_get_peer:  Node 3 has uuid 3
pacemakerd:   notice: crm_update_peer_state:         pcmk_quorum_notification: Node virt-131[3] - state is now member (was (null))
cib:     info: cib_process_ping:      Reporting our current digest to virt-129: a376e2e985dcd9996add4737f8416e41 for 0.15.22 (0x825930 0)
cib:     info: pcmk_cpg_membership:   Joined[14.0] cib.3
cib:     info: pcmk_cpg_membership:   Member[14.0] cib.1
cib:     info: pcmk_cpg_membership:   Member[14.1] cib.3
cib:     info: crm_update_peer_proc:  pcmk_cpg_membership: Node virt-127[3] - corosync-cpg is now online
cib:     info: pcmk_cpg_membership:   Member[14.2] cib.4
cib:     info: pcmk_cpg_membership:   Member[14.3] cib.5
attrd:     info: crm_dump_peer_hash:     crm_find_peer: Node 4/virt-128 = 0x2506230 - 7455b5f9-5dbf-4699-b29c-fc95c789dbbb
attrd:     info: crm_dump_peer_hash:     crm_find_peer: Node 6/virt-130 = 0x2506370 - 59912113-f30a-4b72-b615-809c7c7f97d0
attrd:     info: crm_dump_peer_hash:     crm_find_peer: Node 5/virt-129 = 0x25062d0 - d777a0c1-aac6-4998-bbc3-662541f2a22c
attrd:     info: crm_dump_peer_hash:     crm_find_peer: Node 7/virt-131 = 0x2506440 - d1aa5661-f9d0-4bdc-93d5-3062e0b44659
attrd:     info: crm_dump_peer_hash:     crm_find_peer: Node 1/virt-122 = 0x24830f0 - ad564e5c-7241-4f3f-8d2d-c3ac28fdcfcb
attrd:     info: crm_dump_peer_hash:     crm_find_peer: Node 2/virt-126 = 0x2506610 - dff4adfe-62f0-4e4d-a3c0-5e07b012b6b7
attrd:     info: crm_dump_peer_hash:     crm_find_peer: Node 3/virt-127 = 0x2508f40 - 45e96061-3b19-4a19-9837-5586e0ef1752
attrd:  warning: crm_find_peer:     Node 'virt-127' and 'virt-131' share the same cluster nodeid: 3 virt-131
attrd:    error: crm_abort:     crm_find_peer: Forked child 20878 to record non-fatal assert at membership.c:394 : member weirdness

I do not know how pacemaker's internal peer cache works, but this snippet of a log hints it is still somehow aware of the nodes after they've been removed.

When checking runtime CIB, a CIB stored in /var/lib/pacemaker, corosync quorum and corosync.conf file, the virt-127 node was mentioned i neither of those (besides a related fencing resource).



> Version-Release number of selected component (if applicable):

pacemaker-1.1.12-9.el7.x86_64
corosync-2.3.4-3.el7.x86_64
pcs-0.9.135-1.el7.x86_64 


> How reproducible:

Relatively Easy


> Steps to Reproduce:

1) Setup a cluster of i.e. 7 nodes, with nodes marked n1 to n7
2) Stop node n6 with pcs
3) Remove node n2 with pcs
4) Remove node n7 with pcs
5) Remove node n3 with pcs
6) Add node n7 with pcs
7) Compare node ID assignment before and after these steps - if a different ID was reused by n7 when added back to the cluster, it will most likely cause these errors.


> Actual results:

When the node is added back with a reused ID, membership errors appear in the logs and some pacemakr components will start crashing:

attrd:  warning: crm_find_peer:     Node 'virt-127' and 'virt-131' share the same cluster nodeid: 3 virt-131
attrd:    error: crm_abort:     crm_find_peer: Forked child 20878 to record non-fatal assert at membership.c:394 : member weirdness 


> Expected results:

Reusing of a node ID is not fatal and doesn't cause any membership errors.


> Additional info:

Feel free to reassign this bug to a different component shouldn't pacemaker be at fault here.

Comment 5 Andrew Beekhof 2015-01-23 00:58:18 UTC
Patch for this is:
   https://github.com/beekhof/pacemaker/commit/ddccf97

Forgot to update bugzilla with build information

Comment 9 Andrew Beekhof 2015-03-27 05:24:58 UTC
Guilty.

The patch https://github.com/ClusterLabs/pacemaker/commit/bf15d36 assumed that 'node->state' was hooked up for the cib.  This seems not to be the case, so I'm testing a patch that would address that part so that the original patch will work.

Apologies.

Comment 10 Andrew Beekhof 2015-03-27 05:29:43 UTC
This looks better:

Mar 27 16:26:10 [27091] pcmk-1        cib:     info: crm_update_peer_proc: 	pcmk_cpg_membership: Node pcmk-3[103] - corosync-cpg is now offline
Mar 27 16:26:10 [27091] pcmk-1        cib:     info: cib_peer_update_callback: 	2 103 member
Mar 27 16:26:10 [27091] pcmk-1        cib:   notice: crm_update_peer_state: 	cib_peer_update_callback: Node pcmk-3[103] - state is now lost (was member)
Mar 27 16:26:10 [27091] pcmk-1        cib:     info: cib_peer_update_callback: 	1 103 lost
Mar 27 16:26:10 [27091] pcmk-1        cib:   notice: crm_reap_dead_member: 	Removing pcmk-3/103 from the membership list
Mar 27 16:26:10 [27091] pcmk-1        cib:   notice: reap_crm_member: 	Purged 1 peers with id=103 and/or uname=(null) from the membership cache

The node dropping out from CPG is now automatically removing the node from the cache - so there is nothing for the new node to conflict with.

Comment 11 Andrew Beekhof 2015-03-29 23:23:50 UTC
Also needed:

+ 0b98ef1: Fix: stonith-ng: Correctly track node state  (HEAD, 1.1)
+ 72b3a9a: Fix: stonith-ng: No reply is needed for CRM_OP_RM_NODE_CACHE

Comment 16 errata-xmlrpc 2015-11-19 12:12:02 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHSA-2015-2383.html