Identify unplanned start/stop of the ASCS/ERS services

This document (000020661) is provided subject to the disclaimer at the end of this document.

Environment

SLES for SAP Applications 12 all Service Packs
SLES for SAP Applications 15 all Service Packs

Situation

ASCS or ERS instance seems to have stopped on its own without any trigger. Messages are logged similar to:

2022-04-30T03:34:21.602866+10:00 node2 sap_suse_cluster_connector[14494]: lsr call (out=/tmp/sapha-tmp-ZF8NK3,sid=TST,ino=62)

2022-04-30T03:34:21.887408+10:00 node2 sap_suse_cluster_connector[14494]: Resource rsc_sap_TST_ERS10 with InstanceName=TST_ERS10_saptsters found

2022-04-30T03:34:21.906282+10:00 node2 sap_suse_cluster_connector[14494]: lsr result: TST:62:rsc_sap_TST_ERS10::

2022-04-30T03:34:21.947869+10:00 node2 sap_suse_cluster_connector[14504]: cpa call (res=rsc_sap_TST_ERS10,act=stop)

2022-04-30T03:34:22.031402+10:00 node2 sap_suse_cluster_connector[14509]: fra call (res=rsc_sap_TST_ERS10,act=stop,nod=)

2022-04-30T03:34:22.031901+10:00 node2 sap_suse_cluster_connector[14509]: fire_resource_action stop rsc_sap_TST_ERS10

Resolution

There is nothing that is required to be done. It is important to understand the cause which is discussed below.

Cause

The STOP of SAP instance in an ASCS/ERS cluster from outside the cluster can either be done by a trusted connection or by a trusted system user (OS user).

unix-domain-socket used by "sap_suse_cluster_connector" falls into the category of trusted connection.
"sap_suse_cluster_connector" is used by "sapcontrol" command and SAP GUI (Browser console, SAP JAVA MC, SAP MMC snapin) to start/stop the SAP instances. Any use of sapcontrol command or SAP GUI to stop the SAP instance should result in above logs.

Any other method of start/stop like "startsap or stopsap" which doesn't use "sap_suse_cluster_connector" in an ASCS/ERS cluster is not supported by SUSE.

To Identify whether the stop of SAP instance has been initiated from inside the cluster or outside the cluster we have to look at the logs.

Any stop initiated from outside the clster will log 2 events generated by sap_suse_cluster_connector as shown in example logs below:

--Event 1 logged by sap_suse_cluster_connector----

2022-04-30T03:34:21.602866+10:00 node2 sap_suse_cluster_connector[14494]: lsr call (out=/tmp/sapha-tmp-ZF8NK3,sid=TST,ino=62)

2022-04-30T03:34:21.887408+10:00 node2 sap_suse_cluster_connector[14494]: Resource rsc_sap_TST_ERS10 with InstanceName=TST_ERS10_saptsters found

2022-04-30T03:34:21.906282+10:00 node2 sap_suse_cluster_connector[14494]: lsr result: TST:62:rsc_sap_TST_ERS10::

2022-04-30T03:34:21.947869+10:00 node2 sap_suse_cluster_connector[14504]: cpa call (res=rsc_sap_TST_ERS10,act=stop)

2022-04-30T03:34:22.031402+10:00 node2 sap_suse_cluster_connector[14509]: fra call (res=rsc_sap_TST_ERS10,act=stop,nod=)

2022-04-30T03:34:22.031901+10:00 node2 sap_suse_cluster_connector[14509]: fire_resource_action stop rsc_sap_TST_ERS10

--followed by a pacemaker-execd log to stop the cluster resource for the SAP instance----

2022-04-30T03:34:22.347783+10:00 node2 pacemaker-execd[1961]:  notice: executing - rsc:rsc_sap_TST_ERS10 action:stop call_id:286

--followed by event 2 logged by sap_suse_cluster_connector----

2022-04-30T03:34:22.424443+10:00 node2 sap_suse_cluster_connector[14509]:  rc=0

2022-04-30T03:34:22.473067+10:00 node2 sap_suse_cluster_connector[14579]: lsr call (out=/tmp/sapha-tmp-1nMRO8,sid=TST,ino=62)

2022-04-30T03:34:22.769084+10:00 node2 sap_suse_cluster_connector[14579]: Resource rsc_sap_TST_ERS10 with InstanceName=TST_ERS10_saptsters found

2022-04-30T03:34:22.787754+10:00 node2 sap_suse_cluster_connector[14579]: lsr result: TST:10:rsc_sap_TST_ERS10::

2022-04-30T03:34:22.830920+10:00 node2 sap_suse_cluster_connector[14591]: cpa call (res=rsc_sap_TST_ERS10,act=stop)

2022-04-30T03:34:22.847541+10:00 node2 sap_suse_cluster_connector[14591]: Pending action rsc_sap_TST_ERS10 (node=node2, call=-1, rc=193, last-rc-change=Sat Apr 30 03:34:22 2022, exec=0ms): pending for rsc_sap_TST_ERS10 found

Any stop initiated from inside the cluster such as "crm resource stop" or "crm resource migrate" will log one event from a cluster related process and only one event generated by sap_suse_cluster_connector as shown in example below:

--Event generated by cluster process----

2022-04-22T04:08:14.807129+10:00 node3 pacemaker-schedulerd[12296]:  warning: Processing failed monitor of rsc_sap_LAB_ERS22 on node4: unknown error

2022-04-22T04:08:14.807485+10:00 node3 pacemaker-schedulerd[12296]:  warning: Processing failed monitor of rsc_sap_LAB_ASCS21 on node3: unknown error

2022-04-22T04:08:14.808025+10:00 node3 pacemaker-schedulerd[12296]:  warning: Forcing rsc_sap_LAB_ASCS21 away from node3 after 1 failures (max=1)

2022-04-22T04:08:14.809571+10:00 node3 pacemaker-schedulerd[12296]:  notice:  * Move       fs_LAB_ASCS            ( node3 -> node4 )

2022-04-22T04:08:14.809743+10:00 node3 pacemaker-schedulerd[12296]:  notice:  * Move       nc_LAB_ASCS            ( node3 -> node4 )

2022-04-22T04:08:14.809856+10:00 node3 pacemaker-schedulerd[12296]:  notice:  * Move       vip_LAB_ASCS           ( node3 -> node4 )

2022-04-22T04:08:14.809962+10:00 node3 pacemaker-schedulerd[12296]:  notice:  * Move       rsc_sap_LAB_ASCS21     ( node3 -> node4 )

2022-04-22T04:08:14.810825+10:00 node3 pacemaker-schedulerd[12296]:  notice: Calculated transition 3390, saving inputs in /var/lib/pacemaker/pengine/pe-input-76.bz2

2022-04-22T04:08:14.811655+10:00 node3 pacemaker-controld[12297]:  notice: Processing graph 3390 (ref=pe_calc-dc-1650564494-3455) derived from /var/lib/pacemaker/pengine/pe-input-76.bz2

2022-04-22T04:08:14.811911+10:00 node3 pacemaker-controld[12297]:  notice: Initiating stop operation rsc_sap_LAB_ASCS21_stop_0 locally on node3

2022-04-22T04:08:14.813312+10:00 node3 pacemaker-execd[12294]:  notice: executing - rsc:rsc_sap_LAB_ASCS21 action:stop call_id:48

2022-04-22T04:08:14.813495+10:00 node3 pacemaker-controld[12297]:  notice: Initiating monitor operation rsc_sap_LAB_ERS22_monitor_11000 on node4

--followed by event generated by sap_suse_cluster_connector----

2022-04-22T04:08:15.325865+10:00 node3 sap_suse_cluster_connector[17172]: lsr call (out=/tmp/sapha-tmp-dhEr9C,sid=LAB,ino=31)

2022-04-22T04:08:15.614412+10:00 node3 sap_suse_cluster_connector[17172]: Resource rsc_sap_LAB_ASCS21 with InstanceName=LAB_ASCS21_saplabscs found

2022-04-22T04:08:15.628491+10:00 node3 sap_suse_cluster_connector[17172]: lsr result: LAB:31:rsc_sap_LAB_ASCS21::

2022-04-22T04:08:15.668454+10:00 node3 sap_suse_cluster_connector[17182]: cpa call (res=rsc_sap_LAB_ASCS21,act=stop)

2022-04-22T04:08:15.681005+10:00 node3 sap_suse_cluster_connector[17182]: Pending action rsc_sap_LAB_ASCS21_stop_0 (node=node3, call=-1, rc=193, last-rc-change=Fri Apr 22 04:08:14 2022, exec=0ms): pending for rsc_sap_LAB_ASCS21 found

Additional Information

Looking at following logs can provide further information on the sequence of events leading to the stop of SAP instance.
$(DIR_HOME)/sapstartsrv.log(.old)
$(DIR_HOME)/sapstart.log(.old)
sap_suse_cluster_connector.*
/var/log/messages(system log)

Additionally, following manual pages should be referred to for understanding the behaviour of the cluster and its resource agents relevant to this case.
sap_suse_cluster_connector(8)
ocf_heartbeat_SAPInstance(7)
ocf_suse_SAPStartSrv(7)
crm(8)

Disclaimer

This Support Knowledgebase provides a valuable tool for SUSE customers and parties interested in our products and solutions to acquire information, ideas and learn from one another. Materials are provided for informational, personal or non-commercial use within your organization and are presented "AS IS" WITHOUT WARRANTY OF ANY KIND.