#2884 amfd: saAmfSISUHAState is incorrectly overwriten by pending IMM update job

[Minh Hon Chau]

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

[Minh Hon Chau]

attach amfd trace

[Gary Lee]

develop:

commit 16ae837cd07d61f931b1b07fbe84af985ca8a419
Author: Gary Lee gary.lee@dektech.com.au
Date: Wed Jul 11 03:39:57 2018 +0000

amfd: check for queued updates on attribute [#2884]

If there is a queued update on a particular object's attribute,
also queue further 'sync' updates so we don't end up with an
inconsistent value.

[Gary Lee]

release:

commit 9d186562ba59012460f66ccee6c3608563b7e828
Author: Gary Lee gary.lee@dektech.com.au
Date: Wed Jul 11 03:39:57 2018 +0000

amfd: check for queued updates on attribute [#2884]

If there is a queued update on a particular object's attribute,
also queue further 'sync' updates so we don't end up with an
inconsistent value.