- **status**: fixed --> duplicate
- **Milestone**: future --> never
---
** [tickets:#286] Updation of IMM database regarding the nodes information, is
taking long time even after opensaf is up on all the nodes (TCP)**
**Status:** duplicate
**Milestone:** never
**Created:** Tue May 21, 2013 06:24 AM UTC by Mathi Naickan
**Last Updated:** Wed Jun 05, 2013 06:19 AM UTC
**Owner:** A V Mahesh (AVM)
Changeset: 3062
Setup: SLES 11 x86 VirtualBox?
OpenSAF is started simultaneously on three nodes SC-1, SC-2 and PL-3 with TCP
as MDS TRANSPORT and UNIX as INTRANODE TRANSPORT
The following are the console outputs and the times taken:
Opensafd status command take long time to show the information about the nodes
eventhough opensafd is up on all the three nodes:
The following is the output taken on SC-1 for a frequency of almost 1 second:
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd start
Thu Nov 24 12:05:29 IST 2011
Starting OpenSAF Services: done
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:05:56 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:05:58 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:05:59 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:01 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:02 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:04 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:05 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:06 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:07 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:08 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:09 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:10 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:11 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:12 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:13 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:14 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:15 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:16 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:18 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:19 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:20 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:22 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:23 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:24 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:25 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:26 IST 2011
safSISU=safSu=SC-1\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?2,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:27 IST 2011
safSISU=safSu=SC-1\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?2,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:28 IST 2011
safSISU=safSu=SC-1\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?2,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:30 IST 2011
safSISU=safSu=SC-1\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?2,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:31 IST 2011
safSISU=safSu=SC-1\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?2,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-2\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?1,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:32 IST 2011
safSISU=safSu=SC-1\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?2,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-2\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?1,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:33 IST 2011
safSISU=safSu=SC-1\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?2,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-2\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?1,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-2\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF
saAmfSISUHAState=STANDBY(2)
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:06:34 IST 2011
safSISU=safSu=SC-1\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?2,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-2\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?1,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-2\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF
saAmfSISUHAState=STANDBY(2)
safSISU=safSu=PL-3\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?8,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
The following is the observation in case of TIPC:
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd start; date;
Thu Nov 24 12:13:21 IST 2011
Starting OpenSAF Services: done
Thu Nov 24 12:13:25 IST 2011
SLES11-SLOT-1:~ # date; /etc/init.d/opensafd status
Thu Nov 24 12:13:28 IST 2011
safSISU=safSu=SC-1\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?2,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=PL-3\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?1,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-1\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-2\,safSg=NoRed?\,safApp=OpenSAF,safSi=NoRed?8,safApp=OpenSAF
saAmfSISUHAState=ACTIVE(1)
safSISU=safSu=SC-2\,safSg=2N\,safApp=OpenSAF,safSi=SC-2N,safApp=OpenSAF
saAmfSISUHAState=STANDBY(2)
Changed 18 months ago by anders
Sounds like the same problem as in #2333, #2329 (and #1459).
in reply to: ↑ 1 Changed 18 months ago by pavan
Replying to anders:
Sounds like the same problem as in #2333, #2329 (and #1459).
This issue has been observed from the changeset 2918. So I think this ticket is
not related to the above ones.
Changed 13 months ago by ehsjoar
milestone changed from 4.2.1 to future_releases
TLC meeting 2012
Moved all major/minor non-accepted to future release.
The new process is for developers to pull from this pile.
Changed 2 months ago by mahesh
owner set to mahesh
status changed from new to accepted
Changed 2 months ago by mahesh
owner changed from mahesh to nagendra
status changed from accepted to assigned
component changed from opensaf to saf/avsv
Based on the initial analysis , the delay because the way the AVD creating an
SaAmfSIAssignment run-time object in IMM.
Currently AVD Queue all IMM Runtime object activites for later execution ( non
blocking ) for both "safApp=OpenSAF" ( middle-ware )and Non "safApp=OpenSAF" (
non middle-ware ) application , that is why ,susi Runtime Objects creation gets
delayed even after opensaf is up on all the nodes .So moving the bug AVSV.
The following workaround , fixed the problem . This patch try to create
"safApp=OpenSAF" susi immobects Instantly , if not successful at that
point of time, Queues it .
Till the final fix , interested can use the workaround patch .
=====================================================================================diff
—git a/osaf/services/saf/avsv/avd/avd_siass.c
b/osaf/services/saf/avsv/avd/avd_siass.c
— a/osaf/services/saf/avsv/avd/avd_siass.c
+++ b/osaf/services/saf/avsv/avd/avd_siass.c
@@ -49,6 +49,7 @@ static void avd_create_susi_in_imm(SaAmf?
const SaNameT *si_dn, const SaNameT *su_dn)
{
SaNameT dn;
+ SaAisErrorT rc;
SaAmfHAReadinessStateT saAmfSISUHAReadinessState =
SA_AMF_HARS_READY_FOR_ASSIGNMENT;
void *arr1[] = { &dn };
void *arr2[] = { &ha_state };
@@ -82,7 +83,16 @@ static void avd_create_susi_in_imm(SaAmf?
return;
avsv_create_association_class_dn(su_dn, NULL, "safSISU", &dn);
- avd_saImmOiRtObjectCreate("SaAmfSIAssignment", si_dn, attrValues);
+ if (strstr( (char *) su_dn->value, "safApp=OpenSAF") != NULL) {
+ rc = saImmOiRtObjectCreate_2( avd_cb->immOiHandle ,"SaAmfSIAssignment",
si_dn, attrValues);
+ if (rc != SA_AIS_OK) {
+ avd_saImmOiRtObjectCreate("SaAmfSIAssignment", si_dn, attrValues);
+ }
+ }
+ else {
+ avd_saImmOiRtObjectCreate("SaAmfSIAssignment", si_dn, attrValues);
+ }
+
}
/** Delete an SaAmfSIAssignment from IMM
=====================================================================================
Changed 6 weeks ago by neelakanta
owner changed from nagendra to neelakanta
Changed 6 weeks ago by neelakanta
status changed from assigned to accepted
Changed 6 weeks ago by neelakanta
Analyzed the IMM OI API saImmOiRtObjectUpdate_2, that updates the run time
objects.
The test is performed when the standby controller is joining the cluster.
For both TCP and TIPC testing is done on same machines.
TCP traces for an saImmOiRtObjectUpdate_2 :
==========================================
AMFD —>IMMND
Apr 3 16:06:48.483071 osafamfd [21339:imma_oi_api.c:2258] >>
saImmOiRtObjectUpdate_2
IMMND —> IMMD
Apr 3 16:06:48.484541 osafimmnd [21260:ImmModel.cc:12393] >> rtObjectUpdate:
cont:0x7fffa3a7e4c8 connp:0x7fffa3a7e4cc nodep:(nil)
Apr 3 16:06:48.484687 osafimmnd [21260:ImmModel.cc:12407] T5 Update runtime
attributes in object 'safComp=GLND,safSu=SC-2,safSg=NoRed?,safApp=OpenSAF'
Apr 3 16:06:48.485335 osafimmnd [21260:immsv_evt.c:5117] T8 Sending:
IMMD_EVT_ND2D_OI_OBJ_MODIFY to 0
Apr 3 16:06:48.489838 osafimmnd [21260:immnd_evt.c:2508] <<
immnd_evt_proc_rt_update
IMMD (Broadcast) —> IMMND
Apr 3 16:06:48.486463 osafimmd [21245:immd_evt.c:1857] >>
immd_evt_proc_rt_modify_req
Apr 3 16:06:48.486766 osafimmd [21245:immd_evt.c:0223] >> immd_evt_proc_fevs_req
Apr 3 16:06:48.486890 osafimmd [21245:immd_evt.c:0263] T5
immd_evt_proc_fevs_req send_count:1261 size:125
Apr 3 16:06:48.531440 osafimmd [21245:immd_mds.c:0750] >> immd_mds_bcast_send
Apr 3 16:06:48.531511 osafimmd [21245:immsv_evt.c:5122] T8 Sending:
IMMND_EVT_D2ND_GLOB_FEVS_REQ to 0
Apr 3 16:06:48.543118 osafimmd [21245:immd_mds.c:0770] << immd_mds_bcast_send
Apr 3 16:06:48.543129 osafimmd [21245:immd_evt.c:0325] << immd_evt_proc_fevs_req
Apr 3 16:06:48.543137 osafimmd [21245:immd_evt.c:1922] <<
immd_evt_proc_rt_modify_req
IMMND —> AMFD
Apr 3 16:06:48.533183 osafimmnd [21260:immsv_evt.c:5136] T8 Received:
IMMND_EVT_A2ND_OI_OBJ_MODIFY (38) from 0
Apr 3 16:06:48.533287 osafimmnd [21260:immnd_evt.c:5659] >>
immnd_evt_proc_rt_object_modify
Apr 3 16:06:48.533357 osafimmnd [21260:ImmModel.cc:1656] >>
immModel_rtObjectUpdate
Apr 3 16:06:48.535042 osafimmnd [21260:immnd_evt.c:5856] T2 send reply to
client/agent
Apr 3 16:06:48.543155 osafimmnd [21260:immnd_evt.c:5874] <<
immnd_evt_proc_rt_object_modify
AMFD receives the reply
Apr 3 16:06:48.535515 osafamfd [21339:mds_dt_trans.c:0671] >>
mdtm_process_poll_recv_data_tcp
Apr 3 16:06:48.536249 osafamfd [21339:imma_oi_api.c:2540] <<
saImmOiRtObjectUpdate_2
TIPC traces for an saImmOiRtObjectUpdate_2 :
==========================================
AMFD —>IMMND
Apr 3 15:28:10.231022 osafamfd [8869:imma_oi_api.c:2258] >>
saImmOiRtObjectUpdate_2
IMMND —> IMMD
Apr 3 15:28:10.231260 osafimmnd [8793:ImmModel.cc:12393] >> rtObjectUpdate:
cont:0x7fff5abc5ea8 connp:0x7fff5abc5eac nodep:(nil)
Apr 3 15:28:10.231280 osafimmnd [8793:ImmModel.cc:12407] T5 Update runtime
attributes in object 'safComp=GLND,safSu=SC-2,safSg=NoRed?,safApp=OpenSAF'
Apr 3 15:28:10.231352 osafimmnd [8793:ImmModel.cc:1664] <<
immModel_rtObjectUpdate
Apr 3 15:28:10.231357 osafimmnd [8793:immnd_evt.c:2445] T2
immnd_evt_proc_rt_update was not pure local, i.e. cached RT attrs
Apr 3 15:28:10.231368 osafimmnd [8793:immsv_evt.c:5117] T8 Sending:
IMMD_EVT_ND2D_OI_OBJ_MODIFY to 0
IMMD (Broadcast) —> IMMND
Apr 3 15:28:10.231500 osafimmd [8778:immsv_evt.c:5130] T8 Received:
IMMD_EVT_ND2D_OI_OBJ_MODIFY from 2010f
Apr 3 15:28:10.231568 osafimmd [8778:immd_evt.c:1857] >>
immd_evt_proc_rt_modify_req
Apr 3 15:28:10.232600 osafimmd [8778:immd_mds.c:0750] >> immd_mds_bcast_send
Apr 3 15:28:10.232606 osafimmd [8778:immsv_evt.c:5122] T8 Sending:
IMMND_EVT_D2ND_GLOB_FEVS_REQ to 0
Apr 3 15:28:10.233885 osafimmd [8778:immd_mds.c:0770] << immd_mds_bcast_send
IMMND —> AMFD
Apr 3 15:28:10.232789 osafimmnd [8793:immsv_evt.c:5136] T8 Received:
IMMND_EVT_A2ND_OI_OBJ_MODIFY (38) from 0
Apr 3 15:28:10.232796 osafimmnd [8793:immnd_evt.c:5659] >>
immnd_evt_proc_rt_object_modify
Apr 3 15:28:10.232815 osafimmnd [8793:ImmModel.cc:1656] >>
immModel_rtObjectUpdate
Apr 3 15:28:10.232822 osafimmnd [8793:ImmModel.cc:1658] T5 on enter isPl:0
Apr 3 15:28:10.232828 osafimmnd [8793:ImmModel.cc:12393] >> rtObjectUpdate:
cont:0x7fff5abc5654 connp:0x7fff5abc565c nodep:(nil)
Apr 3 15:28:10.232836 osafimmnd [8793:ImmModel.cc:12407] T5 Update runtime
attributes in object 'safComp=GLND,safSu=SC-2,safSg=NoRed?,safApp=OpenSAF'
Apr 3 15:28:10.232942 osafimmnd [8793:ImmModel.cc:1664] <<
immModel_rtObjectUpdate
Apr 3 15:28:10.232949 osafimmnd [8793:immnd_evt.c:5856] T2 send reply to
client/agent
Apr 3 15:28:10.233791 osafimmnd [8793:immnd_evt.c:5874] <<
immnd_evt_proc_rt_object_modify
AMFD receives the reply
Apr 3 15:28:10.233027 osafamfd [8869:imma_oi_api.c:2540] <<
saImmOiRtObjectUpdate_2
Following is the observation:
1. TCP is taking 0.05 seconds, for saImmOiRtObjectUpdate_2 to complete. TIPC is
taking 0.002 seconds, for saImmOiRtObjectUpdate_2.
2. TCP is taking more time for sending and receiving each mds send/recv
3. Each middle-ware SU is executing 5 saImmOiRtObjectUpdate_2 operations
between Instantiating and Instantiated.
4. There are 6 No-Red SU's and 11 2N middleware SU's.
5. To get standby assignment for middleware SUSI will take 4 to 5 seconds in
TCP and 1 to 2 seconds in TIPC.
6. Presently as per spec, saImmOiRtObjectUpdate_2 can be delayed by AMF, while
there are other events to process.
7. As the workaround mentioned by Mahesh, in the ticket :
it will update fast at the cost other functional AMF events.
Even though the update is fast, the total time required for middleware SG to
get assigned as standby till takes the same delay(4 to 5 seconds in TCP).
8. If the defect is about the delay, then the root-cause is not the update job
is queued, but the time taken by the update.
Changed 6 weeks ago by hafe
component changed from saf/avsv to opensaf
Good analysis! Move it from AMF to OpenSAF. Where is the time consumed? Are
certain TCP features disabled (don't remember the names) like buffering etc?
---
Sent from sourceforge.net because [email protected] is
subscribed to https://sourceforge.net/p/opensaf/tickets/
To unsubscribe from further messages, a project admin can change settings at
https://sourceforge.net/p/opensaf/admin/tickets/options. Or, if this is a
mailing list, you can unsubscribe from the mailing list.------------------------------------------------------------------------------
Don't Limit Your Business. Reach for the Cloud.
GigeNET's Cloud Solutions provide you with the tools and support that
you need to offload your IT needs and focus on growing your business.
Configured For All Businesses. Start Your Cloud Today.
https://www.gigenetcloud.com/
_______________________________________________
Opensaf-tickets mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/opensaf-tickets
