Menu
▾
▴
Re: [users] [opensaf:tickets] #3306 ckpt: checkpoint node director responding to async call.
|
From: Mohan K. <mohan@GetHighAvailability.com> - 2022-03-09 17:39:05
|
Hi Sergio, We have analyzed the issue. Please find the detail analysis below. 1. When SC-1 is coming up after reboot in the step #4 mentioned by you below, application from PL-2(assumed) is creating a checkpoint replica(ckptnd) and the request goes to Active Ckptd at SC-2(Active): Mar 7 08:26:06 OLT2T4-UNICOM-2 local0.notice osafamfd[1267]: NO Node 'CC-1' joined the cluster Mar 7 08:26:07 OLT2T4-UNICOM-2 local0.notice osafimmnd[1219]: NO Implementer connected: 31 (MsgQueueService133391) <0, 2090f> Mar 7 08:26:07 OLT2T4-UNICOM-2 local0.info osafimmnd[1219]: IN Create runtime object 'safReplica=safNode=CC-1\#safCluster=myClmCluster,safCkpt=CKPT_BACKPLANE_CONTROL,safApp=safCkptService' by Impl id: 22 2. SC-2 Ckptd checkpoints(along with nodes) the information to upcoming Ckptd(Standby) during sync, but the checkpoint addition fails at SC-1 because CLMD doesn’t have node id 136463 in its data base. <143>1 2022-03-07T08:26:07.300294Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="580"] 1288:ckpt/ckptd/cpd_mbcsv.c:1066 >> cpd_mbcsv_dec_sync_resp <143>1 2022-03-07T08:26:07.300481Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="581"] 1288:base/hj_enc.c:418 >> osaf_decode_sanamet <143>1 2022-03-07T08:26:07.300538Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="582"] 1288:base/hj_enc.c:447 TR str: safCkpt=CKPT_BACKPLANE_CONTROL,safApp=safCkptService (52) <143>1 2022-03-07T08:26:07.300638Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="583"] 1288:base/hj_enc.c:451 << osaf_decode_sanamet <143>1 2022-03-07T08:26:07.300831Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="584"] 1288:ckpt/ckptd/cpd_sbevt.c:103 >> cpd_sb_proc_ckpt_create ………………………………. <143>1 2022-03-07T08:26:07.315981Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="630"] 1288:clm/agent/clma_api.cc:1232 << saClmClusterNodeGet <143>1 2022-03-07T08:26:07.316023Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="631"] 1288:ckpt/ckptd/cpd_sbevt.c:192 T4 cpd standby create evt failed for node_id:136463 <143>1 2022-03-07T08:26:07.316069Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="632"] 1288:ckpt/ckptd/cpd_db.c:214 >> cpd_ckpt_node_and_ref_delete <143>1 2022-03-07T08:26:07.316113Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="633"] 1288:ckpt/ckptd/cpd_db.c:1121 >> cpd_ckpt_ref_info_del <143>1 2022-03-07T08:26:07.316154Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="634"] 1288:ckpt/ckptd/cpd_db.c:1143 << cpd_ckpt_ref_info_del <143>1 2022-03-07T08:26:07.316201Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="635"] 1288:ckpt/ckptd/cpd_db.c:244 << cpd_ckpt_node_and_ref_delete <143>1 2022-03-07T08:26:07.316242Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="636"] 1288:ckpt/ckptd/cpd_db.c:666 >> cpd_ckpt_map_node_delete <143>1 2022-03-07T08:26:07.316288Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="637"] 1288:ckpt/ckptd/cpd_db.c:682 << cpd_ckpt_map_node_delete <143>1 2022-03-07T08:26:07.316329Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="638"] 1288:ckpt/ckptd/cpd_sbevt.c:288 << cpd_sb_proc_ckpt_create <143>1 2022-03-07T08:26:07.316368Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="639"] 1288:ckpt/ckptd/cpd_mbcsv.c:1111 T4 cpd standby create evt failed <143>1 2022-03-07T08:26:07.316415Z OLT2T4-UNICOM-1 osafckptd 1288 osafckptd [meta sequenceId="640"] 1288:ckpt/ckptd/cpd_mbcsv.c:1136 << cpd_mbcsv_dec_sync_resp 3. After switchover when SC-1 becomes Active, then it doesn’t have checkpoint information with itself and hence, immlist fails. It looks Active ckptd sends nodes information, which existed before(like on PL-1) and is not available right now. It looks like adding checkpoint replica having some issues. This may be older defects, but because of timing issue, you got it. Workaround: 1. When SC-1 is coming up, then don’t create the same checkpoint until PL-1 is not up. So, you are avoiding to create checkpoint till PL-1 joins the cluster. Or 2. In step #4, start PL-1 first and then SC-1, immlist shouldn’t give any error. Thanks & Regards Mohan Kanakam | 91-8333082448 Senior Software Engineer High Availability Solutions www.GetHighAvailability.com Get High Availability Today ! NJ, USA: 1 508-507-6507 | Hyderabad, India: 91 798-992-5293 From: Sérgio Marques [mailto:ser...@al...] Sent: 07 March 2022 14:59 To: Mohan Kanakam Cc: 'Nagendra Kumar'; ope...@li... Subject: RE: [opensaf:tickets] #3306 ckpt: checkpoint node director responding to async call. Hi Mohan, I’m sending the logs in attach. Please feel free to ask for more info/logs/tests… Many thanks and best regards, Sérgio Marques From: Mohan Kanakam <mohan@GetHighAvailability.com> Sent: 3 de março de 2022 11:34 To: 'Mohan Kanakam' <mohan@GetHighAvailability.com>; Sérgio Marques <ser...@al...> Cc: 'Nagendra Kumar' <nagendra@GetHighAvailability.com>; ope...@li... Subject: RE: [opensaf:tickets] #3306 ckpt: checkpoint node director responding to async call. Atenção: Este email foi originado fora da Altice Portugal. Por favor, não clique em links nem abra anexos, a não ser que conheça o remetente e saiba que o seu conteúdo é seguro. Hi Sergio, We are not able to reproduce the issue as per the steps shared by you on version 5.22.01. So, can you please send us the immd , immnd , ckptd , ckptnd , syslog and mdslog of all the nodes of the cluster. Thanks & Regards Mohan Kanakam | 91-8333082448 Senior Software Engineer High Availability Solutions www.GetHighAvailability.com Get High Availability Today ! NJ, USA: 1 508-507-6507 | Hyderabad, India: 91 798-992-5293 From: Mohan Kanakam [mailto:mohan@GetHighAvailability.com] Sent: 28 February 2022 20:55 To: 'Sérgio Marques' Cc: 'Nagendra Kumar' Subject: RE: [opensaf:tickets] #3306 ckpt: checkpoint node director responding to async call. Hi Sergio, Thanks for the information. We will try to reproduce and get back to you. Thanks & Regards Mohan Kanakam | 91-8333082448 Senior Software Engineer High Availability Solutions www.GetHighAvailability.com Get High Availability Today ! NJ, USA: 1 508-507-6507 | Hyderabad, India: 91 798-992-5293 From: Sérgio Marques [mailto:ser...@al...] Sent: 28 February 2022 20:46 To: Mohan Kanakam Cc: 'Nagendra Kumar' Subject: RE: [opensaf:tickets] #3306 ckpt: checkpoint node director responding to async call. Hi Mohan, I believe I have finally found a way for you to reproduce the problem: Please try the following steps: 1. Start 2 controllers with SC-2 Active and SC-1 Standby and 2 payloads, PL-1 and PL-2. 2. At PL-2 create a checkpoint, a section and write on it. 3. At PL-1 create exactly the same checkpoint created in PL-2 and try to create the same section as previously created. You will receive a SA_AIS_ERR_EXIST. Do a SectionOverwrite. 4. At SC-1 perform a si-swap (amf-adm -t 10 si-swap safSi=SC-2N,safApp=OpenSAF) and reboot SC-1 and PL-1 nodes. 5. Wait for SC-1 and PL-1 to rejoin the cluster. 6. At SC-2 perform a si-swap (amf-adm -t 10 si-swap safSi=SC-2N,safApp=OpenSAF) and then list the checkpoint using immlist. Thanks and regards, Sérgio Marques From: Mohan Kanakam <mohan@GetHighAvailability.com> Sent: 18 de fevereiro de 2022 13:40 To: Sérgio Marques <ser...@al...> Cc: 'Nagendra Kumar' <nagendra@GetHighAvailability.com>; ope...@li... Subject: RE: [opensaf:tickets] #3306 ckpt: checkpoint node director responding to async call. Atenção: Este email foi originado fora da Altice Portugal. Por favor, não clique em links nem abra anexos, a não ser que conheça o remetente e saiba que o seu conteúdo é seguro. Hi Sergio, Thanks for the testing and sharing the results. We try to reproduce the issue in our lab setup, unfortunately we are not able to reproduce. These are the steps we followed : 1. Start 2 controllers with SC-1 Act and SC-2 Standby and PL-3 payload 2. Create checkpoints by applications running on payload 3. Reboot SC-1 (Act). SC-2 becomes Active. And SC-1 joins as Standby. 4. Now perform si-swap. SC-2 becomes Standby and SC-1 becomes Active 5. Reboot SC-1 again. 6. While it is rebooting, perform immlist on checkpoints created. Here we got the output of immlist. Can you please confirm, this is the way to reproduce it or not? Did this issue continue after rebooted controller joined the cluster i.e., immlist worked after rebooted controller joined the cluster? I was thinking that, this could be a transient issue. Can you please share immd, immnd, amfd, amfnd, ckptd, ckptnd, mds.log and syslog from all the nodes. Thanks & Regards Mohan Kanakam | 91-8333082448 Senior Software Engineer High Availability Solutions www.GetHighAvailability.com Get High Availability Today ! NJ, USA: 1 508-507-6507 | Hyderabad, India: 91 798-992-5293 From: Sérgio Marques [mailto:ser...@al...] Sent: 17 February 2022 22:53 To: mohan@GetHighAvailability.com Subject: RE: [opensaf:tickets] #3306 ckpt: checkpoint node director responding to async call. Hi Mohan, I’ve done a small change in your patch to be able of compiling it. Where you have “sinfo->ctxt->length” I’ve changed it to “sinfo->ctxt.length”. It resolves the problem. Now, there is no “MDS_SND_RCV: Invalid Sync CTXT Len” events being registered in mds.log. Thanks! Unfortunately, this does not resolve another issue that we also have and were hoping to resolve it with this patch as well. We set a cluster with 2 controller and 2 payload nodes, then we create a checkpoint like the following one: [root@OLT2T4-UNICOM-2~]# immlist safCkpt=CKPT_BACKPLANE_CONTROL,safApp=safCkptService Name Type Value(s) ======================================================================== safCkpt SA_STRING_T safCkpt=CKPT_BACKPLANE_CONTROL saCkptCheckpointUsedSize SA_UINT64_T 2024 (0x7e8) saCkptCheckpointSize SA_UINT64_T 2024 (0x7e8) saCkptCheckpointRetDuration SA_TIME_T 9223372036854775807 (0x7fffffffffffffff, Sat Jan 27 10:50:44 1990) saCkptCheckpointNumWriters SA_UINT32_T 7 (0x7) saCkptCheckpointNumSections SA_UINT32_T 22 (0x16) saCkptCheckpointNumReplicas SA_UINT32_T 2 (0x2) saCkptCheckpointNumReaders SA_UINT32_T 7 (0x7) saCkptCheckpointNumOpeners SA_UINT32_T 7 (0x7) saCkptCheckpointNumCorruptSections SA_UINT32_T 0 (0x0) saCkptCheckpointMaxSections SA_UINT32_T 22 (0x16) saCkptCheckpointMaxSectionSize SA_UINT64_T 92 (0x5c) saCkptCheckpointMaxSectionIdSize SA_UINT64_T 1 (0x1) saCkptCheckpointCreationTimestamp SA_TIME_T 1645097377000000000 (0x16d48f5929030a00, Thu Feb 17 11:29:37 2022) saCkptCheckpointCreationFlags SA_UINT32_T 2 (0x2) SaImmAttrImplementerName SA_STRING_T safCheckPointService SaImmAttrClassName SA_STRING_T SaCkptCheckpoint SaImmAttrAdminOwnerName SA_STRING_T <Empty> After swapping (amf-adm -t 10 si-swap safSi=SC-2N,safApp=OpenSAF) and rebooting the active controller node for the second time, immlist starts returning SA_AIS_ERR_NO_RESOURCES: [root@OLT2T4-UNICOM-2~]# immlist safCkpt=CKPT_BACKPLANE_CONTROL,safApp=safCkptService error - saImmOmAccessorGet_2 FAILED: SA_AIS_ERR_NO_RESOURCES (18) The checkpoint can be found using immfind but not listed width immlist neither accessed via the libSaCkpt.so library. [root@OLT2T4-UNICOM-2~]# immfind safCkpt=CKPT_BACKPLANE_CONTROL,safApp=safCkptService safCkpt=CKPT_BACKPLANE_CONTROL,safApp=safCkptService safReplica=safNode=CC-1\,safCluster=myClmCluster,safCkpt=CKPT_BACKPLANE_CONTROL,safApp=safCkptService safReplica=safNode=CC-2\,safCluster=myClmCluster,safCkpt=CKPT_BACKPLANE_CONTROL,safApp=safCkptService If I only perform the swap command, without the reboot, this issue is not reproduced. I don’t have this issue with the 4.5.2 OpenSAF version. Do you have an idea of what could cause such thing and how should we debug this issue? Many thanks and regards, Sérgio Marques From: Mohan Kanakam <moh...@us...> Sent: 17 de fevereiro de 2022 10:51 To: [opensaf:tickets] <33...@ti...> Subject: [opensaf:tickets] #3306 ckpt: checkpoint node director responding to async call. Atenção: Este email foi originado fora da Altice Portugal. Por favor, não clique em links nem abra anexos, a não ser que conheça o remetente e saiba que o seu conteúdo é seguro. Hi Sergio, can you please test the attached patch for your scenario and share your observations. thanks Attachments: * mds_error.patch <https://sourceforge.net/p/opensaf/tickets/_discuss/thread/04984c7ecf/8052/attachment/mds_error.patch> (703 Bytes; application/octet-stream) _____ [tickets:#3306] <https://sourceforge.net/p/opensaf/tickets/3306/> ckpt: checkpoint node director responding to async call. Status: accepted Milestone: 5.22.04 Created: Thu Feb 17, 2022 10:46 AM UTC by Mohan Kanakam Last Updated: Thu Feb 17, 2022 10:46 AM UTC Owner: Mohan Kanakam During section create, one ckptnd sends async request(normal mds send) to another ckptnd. But, another ckptnd is responding to the request in assumption that it received the sync request and it has to respond to the sender ckptnd. In few cases, it is needed to respond when a sync req comes to ckptnd, but in few cases, it receives async req and it needn't respond async request. We are getting the following messages in mds log when creating the section: sc1-VirtualBox osafckptnd 27692 mds.log [meta sequenceId="2"] MDS_SND_RCV: Invalid Sync CTXT Len _____ Sent from sourceforge.net because you indicated interest in https://sourceforge.net/p/opensaf/tickets/3306/ To unsubscribe from further messages, please visit https://sourceforge.net/auth/subscriptions/ |