#2093 saLogStreamOpen_2 api returns SA_AIS_ERR_BAD_OPERATION during si-swap operation

[Ritu Raj]

Environment details

OS : Suse 64bit
Changeset : 7997 ( 5.1.FC)
Setup : 4 nodes ( 2 controllers and 2 payloads with headless feature disabled & PBE disabled

Summary

saLogStreamOpen_2 api returns SA_AIS_ERR_BAD_OPERATION during si-swap operation while opening previously closed app stream with same properties

Steps followed & Observed behaviour

1. Open an application stream
2. Close the stream
3. Perform si-swap operation
4. Again, Opening a previously closed stream with same properties during switchover opeartion

saLogStreamOpen_2 api returns Bad return status!!! rc = 20

Below is agent trace:
Oct 5 6:36:19.674354 lga [9272:ntfa_mds.c:0583] << ntfa_mds_enc
Oct 5 6:36:19.676361 lga [9272:ntfa_mds.c:0827] >> ntfa_mds_dec
Oct 5 6:36:19.676399 lga [9272:ntfa_mds.c:0857] T2 NTFSV_NTFA_API_RESP_MSG rc = 1
Oct 5 6:36:19.676414 lga [9272:ntfa_mds.c:0936] << ntfa_mds_dec
Oct 5 6:36:19.676815 lga [9272:ntfa_mds.c:1202] << ntfa_mds_msg_sync_send
Oct 5 6:36:19.676863 lga [9272:ntfa_api.c:2128] T1 subscriptionId from server 18681
Oct 5 6:36:19.676893 lga [9272:ntfa_api.c:2170] << saNtfNotificationSubscribe
Oct 5 6:36:31.472555 lga [9272:lga_api.c:0774] >> saLogStreamOpen_2
Oct 5 6:36:31.472598 lga [9272:lga_api.c:0613] >> validate_open_params
Oct 5 6:36:31.472608 lga [9272:lga_api.c:0740] << validate_open_params
Oct 5 6:36:31.472618 lga [9272:lga_api.c:0082] >> populate_open_params
Oct 5 6:36:31.472624 lga [9272:lga_api.c:0107] << populate_open_params
Oct 5 6:36:31.472643 lga [9272:lga_mds.c:1285] >> lga_mds_msg_sync_send
Oct 5 6:36:31.472672 lga [9272:lga_mds.c:0706] >> lga_mds_enc
Oct 5 6:36:31.472682 lga [9272:lga_mds.c:0737] T2 msgtype: 0
Oct 5 6:36:31.472688 lga [9272:lga_mds.c:0750] T2 api_info.type: 2
Oct 5 6:36:31.472694 lga [9272:lga_mds.c:0122] >> lga_enc_lstr_open_sync_msg
Oct 5 6:36:31.472702 lga [9272:lga_mds.c:0247] << lga_enc_lstr_open_sync_msg
Oct 5 6:36:31.472707 lga [9272:lga_mds.c:0778] << lga_mds_enc
Oct 5 6:36:31.579120 lga [9272:lga_mds.c:0591] >> lga_mds_svc_evt
Oct 5 6:36:31.579154 lga [9272:lga_mds.c:0595] TR lga_mds_svc_evt NCSMDS_NO_ACTIVE
Oct 5 6:36:31.579165 lga [9272:lga_mds.c:0599] TR NCSMDS_NO_ACTIVE
Oct 5 6:36:31.579174 lga [9272:lga_mds.c:0650] << lga_mds_svc_evt
Oct 5 6:36:31.583167 lga [9272:lga_mds.c:0977] >> lga_mds_dec
Oct 5 6:36:31.583211 lga [9272:lga_mds.c:1009] T2 LGSV_LGA_API_RESP_MSG
Oct 5 6:36:31.583227 lga [9272:lga_mds.c:1060] << lga_mds_dec
Oct 5 6:36:31.583306 lga [9272:lga_mds.c:1312] << lga_mds_msg_sync_send
Oct 5 6:36:31.583323 lga [9272:lga_api.c:0921] TR Bad return status!!! rc = 20
Oct 5 6:36:31.583336 lga [9272:lga_api.c:0970] << saLogStreamOpen_2
Oct 5 6:36:32.492387 lga [9272:ntfa_mds.c:0388] T2 NTFA Rcvd MDS subscribe evt from svc 28
Oct 5 6:36:32.492427 lga [9272:ntfa_mds.c:0398] TR NTFS down

**Notes:
Agent trace attached

[Vu Minh Nguyen]

Can you provide syslog or osaflogd trace? Thanks.

[Ritu Raj]

Below is the output of osaflogd, here I am seeing imma_oi_api.c returns ERR_BAD_OPERATION: The SaImmOiHandleT is not associated with any implementer name

---

Oct 5 9:35:16.952210 osaflogd [12979:imma_oi_api.c:2786] >> rt_object_create_common
Oct 5 9:35:16.952697 osaflogd [12979:imma_oi_api.c:2838] ER ERR_BAD_OPERATION: The SaImmOiHandleT is not associated with any implementer name
Oct 5 9:35:16.952720 osaflogd [12979:imma_oi_api.c:3063] << rt_object_create_common
Oct 5 9:35:16.952747 osaflogd [12979:lgs_stream.cc:0590] WA saImmOiRtObjectCreate_2 returned 20 for safLgStr=test_app_stream1, parent (null)
Oct 5 9:35:16.952756 osaflogd [12979:lgs_stream.cc:0595] << lgs_create_rt_appstream: rc: SA_AIS_ERR_BAD_OPERATION (20)
Oct 5 9:35:16.952763 osaflogd [12979:lgs_stream.cc:0375] >> log_stream_delete: safLgStr=test_app_stream1
Oct 5 9:35:16.952770 osaflogd [12979:lgs_stream.cc:0380] TR Stream is closed, I am HA active so remove IMM object

• syslog attached
• osaflogd tarce attached

[Vu Minh Nguyen]

I just sent out the patch for review. It is good if you can apply the patch and test it.

[Vu Minh Nguyen]

changeset: 8216:90192f4b8e98
tag: tip
parent: 8213:32824c74a736
user: Vu Minh Nguyen vu.m.nguyen@dektech.com.au
date: Wed Oct 12 16:03:09 2016 +0700
summary: log: fix saLogStreamOpen_2 returns SA_AIS_ERR_BAD_OPERATION during si-swap [#2093]

changeset: 8215:f86e8509a000
branch: opensaf-5.1.x
parent: 8212:38f928e934cc
user: Vu Minh Nguyen vu.m.nguyen@dektech.com.au
date: Wed Oct 12 16:03:09 2016 +0700
summary: log: fix saLogStreamOpen_2 returns SA_AIS_ERR_BAD_OPERATION during si-swap [#2093]

changeset: 8214:7614e1f897a8
branch: opensaf-5.0.x
parent: 8211:9a42c66ed888
user: Vu Minh Nguyen vu.m.nguyen@dektech.com.au
date: Thu Oct 13 11:28:42 2016 +0700
summary: log: fix saLogStreamOpen_2 returns SA_AIS_ERR_BAD_OPERATION during si-swap [#2093]