After si-swap, saAmfSISUHAState of SISU 2N Opensaf remains QUIESCED forever in IMM.
Below is scenario that causes this issue.
amfd receives QUIESCED state transition assignment response, amfd updates the saAmfSISUHAState but it couldn't, so push this update job to queue.
<143>1 2018-06-26T05:44:25.089721+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24891"] 271:amf/amfd/sgproc.cc:1172 >> avd_su_si_assign_evh: id:63, node:2010f, act:5, 'safSu=SC-1,safSg=2N,safApp=OpenSAF', '', ha:3, err:1, single:0
<143>1 2018-06-26T05:44:25.090099+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24912"] 271:amf/amfd/siass.cc:157 >> avd_susi_update_fsm: SISU:'safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF', old fsm state: 5, new fsm state: 3
<143>1 2018-06-26T05:44:25.090109+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24913"] 271:amf/amfd/imm.cc:137 >> isImmServiceReady
<143>1 2018-06-26T05:44:25.090116+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24914"] 271:amf/amfd/imm.cc:141 TR No active service
<143>1 2018-06-26T05:44:25.090122+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24915"] 271:amf/amfd/imm.cc:152 << isImmServiceReady: 0:
<143>1 2018-06-26T05:44:25.09013+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24916"] 271:amf/amfd/imm.cc:1753 >> avd_saImmOiRtObjectUpdate_sync: 'safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF' osafAmfSISUFsmState
<143>1 2018-06-26T05:44:25.090138+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24917"] 271:amf/amfd/imm.cc:1874 >> avd_saImmOiRtObjectUpdate: 'safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF' osafAmfSISUFsmState
<143>1 2018-06-26T05:44:25.090148+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24918"] 271:amf/amfd/imm.cc:1904 << avd_saImmOiRtObjectUpdate
<143>1 2018-06-26T05:44:25.090155+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24919"] 271:amf/amfd/imm.cc:0 << avd_saImmOiRtObjectUpdate_sync
<143>1 2018-06-26T05:44:25.090163+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24920"] 271:amf/amfd/imm.cc:137 >> isImmServiceReady
<143>1 2018-06-26T05:44:25.09017+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24921"] 271:amf/amfd/imm.cc:141 TR No active service
<143>1 2018-06-26T05:44:25.090177+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24922"] 271:amf/amfd/imm.cc:152 << isImmServiceReady: 0:
<143>1 2018-06-26T05:44:25.090184+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24923"] 271:amf/amfd/imm.cc:1753 >> avd_saImmOiRtObjectUpdate_sync: 'safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF' saAmfSISUHAState
<143>1 2018-06-26T05:44:25.090191+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24924"] 271:amf/amfd/imm.cc:1874 >> avd_saImmOiRtObjectUpdate: 'safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF' saAmfSISUHAState
<143>1 2018-06-26T05:44:25.0902+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24925"] 271:amf/amfd/imm.cc:1904 << avd_saImmOiRtObjectUpdate
<143>1 2018-06-26T05:44:25.090207+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24926"] 271:amf/amfd/imm.cc:0 << avd_saImmOiRtObjectUpdate_sync
<143>1 2018-06-26T05:44:25.090214+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="24927"] 271:amf/amfd/siass.cc:173 << avd_susi_update_fsm
amfd receives STANDBY state transition assignment response, amfd can update the saAmfSISUHAState.
<143>1 2018-06-26T05:44:25.211629+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25641"] 271:amf/amfd/sgproc.cc:1172 >> avd_su_si_assign_evh: id:64, node:2010f, act:5, 'safSu=SC-1,safSg=2N,safApp=OpenSAF', '', ha:2, err:1, single:0
<143>1 2018-06-26T05:44:25.211892+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25662"] 271:amf/amfd/siass.cc:157 >> avd_susi_update_fsm: SISU:'safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF', old fsm state: 5, new fsm state: 3
<143>1 2018-06-26T05:44:25.211903+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25663"] 271:amf/amfd/imm.cc:137 >> isImmServiceReady
<143>1 2018-06-26T05:44:25.211909+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25664"] 271:amf/amfd/imm.cc:152 << isImmServiceReady: 1:
<143>1 2018-06-26T05:44:25.211918+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25665"] 271:amf/amfd/imm.cc:1753 >> avd_saImmOiRtObjectUpdate_sync: 'safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF' osafAmfSISUFsmState
<143>1 2018-06-26T05:44:25.211925+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25666"] 271:imm/agent/imma_oi_api.cc:2556 >> rt_object_update_common
<143>1 2018-06-26T05:44:25.219096+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25667"] 274:mds/mds_dt_trans.c:755 >> mdtm_process_poll_recv_data_tcp
<143>1 2018-06-26T05:44:25.219176+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25668"] 271:imm/agent/imma_oi_api.cc:2849 << rt_object_update_common
<143>1 2018-06-26T05:44:25.219198+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25669"] 271:amf/amfd/imm.cc:0 << avd_saImmOiRtObjectUpdate_sync
<143>1 2018-06-26T05:44:25.219205+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25670"] 271:amf/amfd/imm.cc:137 >> isImmServiceReady
<143>1 2018-06-26T05:44:25.219211+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25671"] 271:amf/amfd/imm.cc:152 << isImmServiceReady: 1:
<143>1 2018-06-26T05:44:25.219217+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25672"] 271:amf/amfd/imm.cc:1753 >> avd_saImmOiRtObjectUpdate_sync: 'safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF' saAmfSISUHAState
<143>1 2018-06-26T05:44:25.219223+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25673"] 271:imm/agent/imma_oi_api.cc:2556 >> rt_object_update_common
<143>1 2018-06-26T05:44:25.222896+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25674"] 274:mds/mds_dt_trans.c:755 >> mdtm_process_poll_recv_data_tcp
<143>1 2018-06-26T05:44:25.222978+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25675"] 271:imm/agent/imma_oi_api.cc:2849 << rt_object_update_common
<143>1 2018-06-26T05:44:25.222996+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25676"] 271:amf/amfd/imm.cc:0 << avd_saImmOiRtObjectUpdate_sync
<143>1 2018-06-26T05:44:25.223006+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="25677"] 271:amf/amfd/siass.cc:173 << avd_susi_update_fsm
Now si-swap finishes, amfd still has pending update job of saAmfSISUHAState, amfd updates the saAmfSISUHAState to QUIESCED, which is wrong.
<143>1 2018-06-26T05:44:25.472391+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="26072"] 271:amf/amfd/imm.cc:240 >> exec: Update 'safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF' osafAmfSISUFsmState
<143>1 2018-06-26T05:44:25.472399+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="26073"] 271:amf/amfd/imm.cc:750 >> object_name_to_class_type: safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF
<143>1 2018-06-26T05:44:25.472408+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="26074"] 271:amf/amfd/imm.cc:798 << object_name_to_class_type: 33
<143>1 2018-06-26T05:44:25.472418+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="26075"] 271:imm/agent/imma_oi_api.cc:2556 >> rt_object_update_common
<143>1 2018-06-26T05:44:25.477774+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="26076"] 274:mds/mds_dt_trans.c:755 >> mdtm_process_poll_recv_data_tcp
<143>1 2018-06-26T05:44:25.477881+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="26077"] 271:imm/agent/imma_oi_api.cc:2849 << rt_object_update_common
<143>1 2018-06-26T05:44:25.477911+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="26078"] 271:amf/amfd/imm.cc:275 << exec
<143>1 2018-06-26T05:44:25.477948+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="26083"] 271:amf/amfd/imm.cc:240 >> exec: Update 'safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF' saAmfSISUHAState
<143>1 2018-06-26T05:44:25.477955+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="26084"] 271:amf/amfd/imm.cc:750 >> object_name_to_class_type: safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF
<143>1 2018-06-26T05:44:25.477963+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="26085"] 271:amf/amfd/imm.cc:798 << object_name_to_class_type: 33
<143>1 2018-06-26T05:44:25.47797+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="26086"] 271:imm/agent/imma_oi_api.cc:2556 >> rt_object_update_common
<143>1 2018-06-26T05:44:25.481406+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="26087"] 274:mds/mds_dt_trans.c:755 >> mdtm_process_poll_recv_data_tcp
<143>1 2018-06-26T05:44:25.481504+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="26088"] 271:imm/agent/imma_oi_api.cc:2849 << rt_object_update_common
<143>1 2018-06-26T05:44:25.481531+02:00 SC-1 osafamfd 271 osafamfd [meta sequenceId="26089"] 271:amf/amfd/imm.cc:275 << exec
attach amfd trace
develop:
commit 16ae837cd07d61f931b1b07fbe84af985ca8a419
Author: Gary Lee gary.lee@dektech.com.au
Date: Wed Jul 11 03:39:57 2018 +0000
Last edit: Gary Lee 2018-07-18
release:
commit 9d186562ba59012460f66ccee6c3608563b7e828
Author: Gary Lee gary.lee@dektech.com.au
Date: Wed Jul 11 03:39:57 2018 +0000
Last edit: Gary Lee 2018-07-18