Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1636191

Summary: Notification Pre-demote, Post-Demote, Pre-Stop, Post-Stop is invoked regardless whether it is master or not.
Product: Red Hat Enterprise Linux 7 Reporter: David Liao <dliao>
Component: pacemakerAssignee: Ken Gaillot <kgaillot>
Status: CLOSED NOTABUG QA Contact: cluster-qe <cluster-qe>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 7.4CC: abeekhof, cluster-maint
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-03-27 22:12:18 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:
Attachments:
Description Flags
Log for All replicas for this bug. none

Description David Liao 2018-10-04 16:49:03 UTC 
Created attachment 1490677 [details]
Log for All replicas for this bug.

Description of problem:
Notification Pre-demote, Post-Demote, Pre-Stop, Post-Stop should be invoked only when demote or stop is needed(or performed) on current master. It shouldn't be invoked by all replicas

Here is log for SPE-DL580-07 [Slave -> Master]


Sep 19 20:13:26  ag(scvag)[37452]:    INFO: mssql_validate
Sep 19 20:13:26  ag(scvag)[37452]:    INFO: Resource agent invoked with: notify
Sep 19 20:13:26  ag(scvag)[37452]:    INFO: mssql_notify pre-demote
Sep 19 20:13:26  ag(scvag)[37452]:    INFO: scvag notify : 0
Sep 19 20:13:26 [17238] SPE-DL580-07       lrmd:     info: log_finished:	finished - rsc:scvag action:notify call_id:75 pid:37452 exit-code:0 exec-time:96ms queue-time:0ms
Sep 19 20:13:26 [17241] SPE-DL580-07       crmd:   notice: process_lrm_event:	Result of notify operation for scvag on spe-dl580-07.sys-sqlsvr.local: 0 (ok) | call=75 key=scvag_notify_0 confirmed=true cib-update=0
Sep 19 20:13:26 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	Diff: --- 0.150.32 2
Sep 19 20:13:26 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	Diff: +++ 0.150.33 (null)
Sep 19 20:13:26 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	+  /cib:  @num_updates=33
Sep 19 20:13:26 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	+  /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='scvag_listener']/lrm_rsc_op[@id='scvag_listener_last_0']:  @operation_key=scvag_listener_stop_0, @operation=stop, @transition-key=43:24692:0:74939124-4dd7-4ea4-a132-9f598d155b7f, @transition-magic=0:0;43:24692:0:74939124-4dd7-4ea4-a132-9f598d155b7f, @call-id=60983, @last-run=1537413206, @last-rc-change=1537413206, @exec-time=114
Sep 19 20:13:26 [17236] SPE-DL580-07        cib:     info: cib_process_request:	Completed cib_modify operation for section status: OK (rc=0, origin=spe-dl580-08.sys-sqlsvr.local/crmd/361275, version=0.150.33)
Sep 19 20:13:31 [17236] SPE-DL580-07        cib:     info: cib_process_ping:	Reporting our current digest to spe-dl580-08.sys-sqlsvr.local: 0d44d1e2c672d62d13814e3800bf7364 for 0.150.33 (0x55c64fad5260 0)
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	Diff: --- 0.150.33 2
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	Diff: +++ 0.150.34 (null)
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	+  /cib:  @num_updates=34
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	+  /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='scvag']/lrm_rsc_op[@id='scvag_last_0']:  @operation_key=scvag_demote_0, @operation=demote, @transition-key=11:24692:0:74939124-4dd7-4ea4-a132-9f598d155b7f, @transition-magic=0:1;11:24692:0:74939124-4dd7-4ea4-a132-9f598d155b7f, @call-id=60985, @rc-code=1, @last-run=1537413212, @last-rc-change=1537413212, @exec-time=4711, @exit-reason=2018/09/19 20:13:36 C
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	+  /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='scvag']/lrm_rsc_op[@id='scvag_last_failure_0']:  @operation_key=scvag_demote_0, @operation=demote, @transition-key=11:24692:0:74939124-4dd7-4ea4-a132-9f598d155b7f, @transition-magic=0:1;11:24692:0:74939124-4dd7-4ea4-a132-9f598d155b7f, @exit-reason=2018/09/19 20:13:36 Could not connect to instance: Unresponsive or down read tcp 127.0.0.1:53430->127.0.0.1:
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_process_request:	Completed cib_modify operation for section status: OK (rc=0, origin=spe-dl580-08.sys-sqlsvr.local/crmd/361276, version=0.150.34)
Sep 19 20:13:36 [17239] SPE-DL580-07      attrd:     info: attrd_peer_update:	Setting fail-count-scvag[spe-dl580-08.sys-sqlsvr.local]: 1 -> 2 from spe-dl580-08.sys-sqlsvr.local
Sep 19 20:13:36 [17239] SPE-DL580-07      attrd:     info: attrd_peer_update:	Setting last-failure-scvag[spe-dl580-08.sys-sqlsvr.local]: 1537413205 -> 1537413216 from spe-dl580-08.sys-sqlsvr.local
Sep 19 20:13:36 [17241] SPE-DL580-07       crmd:     info: do_lrm_rsc_op:	Performing key=70:24692:0:74939124-4dd7-4ea4-a132-9f598d155b7f op=scvag_notify_0
Sep 19 20:13:36 [17238] SPE-DL580-07       lrmd:     info: log_execute:	executing - rsc:scvag action:notify call_id:76
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	Diff: --- 0.150.34 2
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	Diff: +++ 0.150.35 (null)
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	+  /cib:  @num_updates=35
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	+  /cib/status/node_state[@id='2']/transient_attributes[@id='2']/instance_attributes[@id='status-2']/nvpair[@id='status-2-fail-count-scvag']:  @value=2
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_process_request:	Completed cib_modify operation for section status: OK (rc=0, origin=spe-dl580-08.sys-sqlsvr.local/attrd/107656, version=0.150.35)
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	Diff: --- 0.150.35 2
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	Diff: +++ 0.150.36 (null)
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	+  /cib:  @num_updates=36
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	+  /cib/status/node_state[@id='2']/transient_attributes[@id='2']/instance_attributes[@id='status-2']/nvpair[@id='status-2-last-failure-scvag']:  @value=1537413216
Sep 19 20:13:36 [17236] SPE-DL580-07        cib:     info: cib_process_request:	Completed cib_modify operation for section status: OK (rc=0, origin=spe-dl580-08.sys-sqlsvr.local/attrd/107657, version=0.150.36)
Sep 19 20:13:36  ag(scvag)[37487]:    INFO: mssql_validate
Sep 19 20:13:36  ag(scvag)[37487]:    INFO: Resource agent invoked with: notify
Sep 19 20:13:36  ag(scvag)[37487]:    INFO: mssql_notify post-demote
Sep 19 20:13:36  ag(scvag)[37487]:    INFO: scvag notify : 0
Sep 19 20:13:36 [17238] SPE-DL580-07       lrmd:     info: log_finished:	finished - rsc:scvag action:notify call_id:76 pid:37487 exit-code:0 exec-time:86ms queue-time:0ms
Sep 19 20:13:36 [17241] SPE-DL580-07       crmd:   notice: process_lrm_event:	Result of notify operation for scvag on spe-dl580-07.sys-sqlsvr.local: 0 (ok) | call=76 key=scvag_notify_0 confirmed=true cib-update=0
Sep 19 20:13:37 [17241] SPE-DL580-07       crmd:     info: do_lrm_rsc_op:	Performing key=48:24693:0:74939124-4dd7-4ea4-a132-9f598d155b7f op=scvag_notify_0
Sep 19 20:13:37 [17238] SPE-DL580-07       lrmd:     info: log_execute:	executing - rsc:scvag action:notify call_id:77
Sep 19 20:13:37  ag(scvag)[37520]:    INFO: mssql_validate
Sep 19 20:13:37  ag(scvag)[37520]:    INFO: Resource agent invoked with: notify
Sep 19 20:13:37  ag(scvag)[37520]:    INFO: mssql_notify pre-stop
Sep 19 20:13:37  ag(scvag)[37520]:    INFO: scvag notify : 0
Sep 19 20:13:37 [17238] SPE-DL580-07       lrmd:     info: log_finished:	finished - rsc:scvag action:notify call_id:77 pid:37520 exit-code:0 exec-time:81ms queue-time:0ms
Sep 19 20:13:37 [17241] SPE-DL580-07       crmd:   notice: process_lrm_event:	Result of notify operation for scvag on spe-dl580-07.sys-sqlsvr.local: 0 (ok) | call=77 key=scvag_notify_0 confirmed=true cib-update=0
Sep 19 20:13:37 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	Diff: --- 0.150.36 2
Sep 19 20:13:37 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	Diff: +++ 0.150.37 (null)
Sep 19 20:13:37 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	+  /cib:  @num_updates=37
Sep 19 20:13:37 [17236] SPE-DL580-07        cib:     info: cib_perform_op:	+  /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='scvag']/lrm_rsc_op[@id='scvag_last_0']:  @operation_key=scvag_stop_0, @operation=stop, @transition-key=3:24693:0:74939124-4dd7-4ea4-a132-9f598d155b7f, @transition-magic=0:0;3:24693:0:74939124-4dd7-4ea4-a132-9f598d155b7f, @call-id=60988, @rc-code=0, @last-run=1537413217, @last-rc-change=1537413217, @exec-time=540
Sep 19 20:13:37 [17236] SPE-DL580-07        cib:     info: cib_process_request:	Completed cib_modify operation for section status: OK (rc=0, origin=spe-dl580-08.sys-sqlsvr.local/crmd/361278, version=0.150.37)
Sep 19 20:13:37 [17241] SPE-DL580-07       crmd:     info: do_lrm_rsc_op:	Performing key=49:24693:0:74939124-4dd7-4ea4-a132-9f598d155b7f op=scvag_notify_0
Sep 19 20:13:37 [17238] SPE-DL580-07       lrmd:     info: log_execute:	executing - rsc:scvag action:notify call_id:78
Sep 19 20:13:37  ag(scvag)[37553]:    INFO: mssql_validate
Sep 19 20:13:37  ag(scvag)[37553]:    INFO: Resource agent invoked with: notify
Sep 19 20:13:37  ag(scvag)[37553]:    INFO: mssql_notify post-stop
Sep 19 20:13:37  ag(scvag)[37553]:    INFO: notify: 2018/09/19 20:13:37 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [scvag]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-scvag]; connection-timeout [899]; health-threshold [3]; action [post-stop]
Sep 19 20:13:37  ag(scvag)[37553]:    INFO: notify: 2018/09/19 20:13:37 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]
Sep 19 20:13:38  ag(scvag)[37553]:    INFO: notify: 2018/09/19 20:13:38 Replica is SECONDARY (2)
Sep 19 20:13:38  ag(scvag)[37553]:    INFO: scvag notify : 0
Sep 19 20:13:38 [17238] SPE-DL580-07       lrmd:     info: log_finished:	finished - rsc:scvag action:notify call_id:78 pid:37553 exit-code:0 exec-time:331ms queue-time:0ms
Sep 19 20:13:38 [17241] SPE-DL580-07       crmd:   notice: process_lrm_event:	Result of notify operation for scvag on spe-dl580-07.sys-sqlsvr.local: 0 (ok) | call=78 key=scvag_notify_0 confirmed=true cib-update=0



How reproducible:
Always.
Comment 2 Ken Gaillot 2018-10-04 17:16:32 UTC 
Actually, this is the desired intent of notifications. The goal is to notify other instances when one instance changes. Some services maintain information about other instances, and notifications let them know about other instances starting, stopping, etc.

If the local node needs to do anything extra, it should be in the demote etc. action itself.
Comment 3 David Liao 2018-10-04 19:04:41 UTC 
If you said so, should pre-promote and post-promote should notify on demoted device as well?
Comment 4 Ken Gaillot 2018-10-04 19:49:53 UTC 
Anytime one or more instances need to be started, stopped, demoted, or promoted, the cluster will call the notify action on all nodes with instances already running.

The resource agent will have access to a number of environment variables listing which nodes will have instances started, which will have instances stopped, etc.

For example in a cluster with nodes node1 through node5:

If node1, node2, and node3 are already running clone instances, and then node4 and node5 are started: notify will be called on node1, node2, and node3, with OCF_RESKEY_CRM_meta_notify_start_uname="node4 node5".

If instances are running on all nodes, and node2 will be demoted and node3 will be promoted: notify will be called on all nodes with OCF_RESKEY_CRM_meta_notify_demote_uname=node2 and OCF_RESKEY_CRM_meta_notify_promote_uname=node3.

So, all active instances (whether promoted or demoted) will get pre-promote/post-promote notifications when any other instance is promoted, and if there are other start/stop/demote events happening in the same transition, they will be included in the same notification.

Pre-promote/post-promote notifications should not be sent if an instance is being demoted but no instance is being promoted.
Comment 5 Ken Gaillot 2019-03-27 22:12:18 UTC 
Hi,

If there are any questions I haven't addressed, feel free to reopen this.