Hi,
It seems under "enhancement" view, the discussion will be taking a little while.
Let's get back this issue under "defect" view. I think the issue is coincidence
of 10s timeout of saNtfNotificationSend and 10s timeout of SIGTERM on ntfimcnd.
When both timers expire, sometimes we see coredump but most of the cases we
don't.
As in the trace file, new active ntfd did still respond the notification_send
request but at that time the ntfimcnd had died. If NtfSend() API expired a bit
earlier (most of the case), main poll of ntfimcnd would have been released for
sigterm.
The sigterm timeout should be set longer than the NtfSend timeout, as logically
during termination supervision period, there could be many NtfSend() to be
called.
It should be:
The sigterm timeout = NtfSend() tiemout x N
For now, we have N = 1, then both timers expired at once in some cases.
My suggestion is N should be 2 (at least)
NtfSend() is set 10s by default for ntfimcnd, that could be more than enough,
since ntfimcnd does not send alarm/security alarm notification, which involve
saf logging, timeout for NtfSend() should be less than 10s for ntfimcnd.
Currently NTFS_WAIT_TIME = 10 secs by default for all APIs, so changing timeout
of NtfSend() could impact the other applications using different APIs. My
another suggestion is using env var for NTFS_WAIT_TIME_ENV timeout (similar as
IMMA_SYNCR_TIMEOUT), by default it still 10s.
Fix for this defect ticket could be:
- Introduce env var NTFS_WAIT_TIME_ENV, default is still 10s
- ntfimcnd set NTFS_WAIT_TIME_ENV=6s, sigterm timeout = 12s
- ntf api get timeout from NTFS_WAIT_TIME_ENV env
- ntfimcnd uses DISPATCH_ONE for immDispatch
I think this fix would add less complication to existing behaviour so that it
could help to solve the issue at application side whose main concern is
ntfimcnd coredump (the upgrade succeeded eventually though), while everyone can
continue discussions as enhancement.
thanks,
Minh
---
** [tickets:#2219] ntfd: circular dependency with osafntfimcnd**
**Status:** assigned
**Milestone:** 5.0.2
**Created:** Thu Dec 08, 2016 05:14 AM UTC by Gary Lee
**Last Updated:** Thu Dec 15, 2016 10:17 AM UTC
**Owner:** Praveen
A circular dependency can be seen when performing a si-swap of
safSi=SC-2N,safApp=OpenSAF:
1. Active NTFD is trying to sync with Standby using MBC
2. Standby NTFD is the process of terminating its local osafntfimcnd. It is
stuck in timedwait_imcn_exit() and cannot reply to the Active.
3. osafntfimcnd [on standby] is trying to send a notfication to Active NTFD
So we have (1) depending on (2) depending on (3) depending on (1)
This results in a temporary deadlock that dramatically slows down NTFD's
ability to process its main dispatch loop. The deadlock only lasts for approx.
1 second, when mbcsv_mds_send_msg() times out. But since there could be lots of
MBC messages to send, sometimes osafntfimcnd is killed with SIGABRT generating
a coredump. The si-swap operation will also timeout.
steps to reproduce
- Run loop of ntftest 32
root@SC-1:~# for i in {1..10}; do ntftest 32; done
- On another terminal, keep swapping 2N Opensaf SI, got coredump after couples
of swaps
root@SC-1:~# amf-adm si-swap safSi=SC-2N,safApp=OpenSAF
...
root@SC-1:~# amf-adm si-swap safSi=SC-2N,safApp=OpenSAF
~~~
SC-2 (active)
There are a lot of send failures. Each taking approx. 1 second to timeout.
During these 1 second timeouts, NTFD cannot process the main dispatch loop.
Dec 7 11:01:37.531772 osafntfd [452:mbcsv_mds.c:0185] >>
mbcsv_mds_send_msg: sending to vdest:e
Dec 7 11:01:37.531781 osafntfd [452:mbcsv_mds.c:0209] TR send type
MDS_SENDTYPE_REDRSP:
Dec 7 11:01:38.537307 osafntfd [452:mbcsv_mds.c:0247] <<
mbcsv_mds_send_msg: failure
Dec 7 11:01:38.537758 osafntfd [452:mbcsv_mds.c:0185] >>
mbcsv_mds_send_msg: sending to vdest:e
Dec 7 11:01:38.537766 osafntfd [452:mbcsv_mds.c:0209] TR send type
MDS_SENDTYPE_REDRSP:
Dec 7 11:01:39.543180 osafntfd [452:mbcsv_mds.c:0247] <<
mbcsv_mds_send_msg: failure
Dec 7 11:01:39.543695 osafntfd [452:mbcsv_mds.c:0185] >>
mbcsv_mds_send_msg: sending to vdest:e
Dec 7 11:01:39.543698 osafntfd [452:mbcsv_mds.c:0209] TR send type
MDS_SENDTYPE_REDRSP:
Dec 7 11:01:40.545252 osafntfd [452:mbcsv_mds.c:0247] <<
mbcsv_mds_send_msg: failure
Dec 7 11:01:40.545719 osafntfd [452:mbcsv_mds.c:0185] >>
mbcsv_mds_send_msg: sending to vdest:e
Dec 7 11:01:40.545726 osafntfd [452:mbcsv_mds.c:0209] TR send type
MDS_SENDTYPE_REDRSP:
Dec 7 11:01:41.551328 osafntfd [452:mbcsv_mds.c:0247] <<
mbcsv_mds_send_msg: failure
Dec 7 11:01:41.551971 osafntfd [452:mbcsv_mds.c:0185] >>
mbcsv_mds_send_msg: sending to vdest:e
Dec 7 11:01:41.551979 osafntfd [452:mbcsv_mds.c:0209] TR send type
MDS_SENDTYPE_REDRSP:
Dec 7 11:01:42.557594 osafntfd [452:mbcsv_mds.c:0247] <<
mbcsv_mds_send_msg: failure
Dec 7 11:01:42.558171 osafntfd [452:mbcsv_mds.c:0185] >>
mbcsv_mds_send_msg: sending to vdest:e
Dec 7 11:01:42.558179 osafntfd [452:mbcsv_mds.c:0209] TR send type
MDS_SENDTYPE_REDRSP:
Dec 7 11:01:43.564051 osafntfd [452:mbcsv_mds.c:0247] <<
mbcsv_mds_send_msg: failure
Dec 7 11:01:43.564874 osafntfd [452:mbcsv_mds.c:0185] >>
mbcsv_mds_send_msg: sending to vdest:e
Dec 7 11:01:43.564883 osafntfd [452:mbcsv_mds.c:0209] TR send type
MDS_SENDTYPE_REDRSP:
Dec 7 11:01:44.572407 osafntfd [452:mbcsv_mds.c:0247] <<
mbcsv_mds_send_msg: failure
Dec 7 11:01:44.573262 osafntfd [452:mbcsv_mds.c:0185] >>
mbcsv_mds_send_msg: sending to vdest:e
Dec 7 11:01:44.573271 osafntfd [452:mbcsv_mds.c:0209] TR send type
MDS_SENDTYPE_REDRSP:
Dec 7 11:01:45.575091 osafntfd [452:mbcsv_mds.c:0247] <<
mbcsv_mds_send_msg: failure
Dec 7 11:01:47.083548 osafntfd [452:mbcsv_mds.c:0185] >>
mbcsv_mds_send_msg: sending to vdest:e
~~~
~~~
SC-1 (standby)
NTFD is trying to terminate osafntfimcnd. While it is doing that, it cannot
reply to NTFD on SC-2. Meanwhile, osafntfimcnd is sending NTF notifications to
NTFD on SC-1.
Dec 7 11:01:35.453151 osafntfd [464:ntfs_imcnutil.c:0316] TR
handle_state_ntfimcn: Terminating osafntfimcnd process
Dec 7 11:01:45.474313 osafntfd [464:ntfs_imcnutil.c:0124] TR Termination
timeout
Dec 7 11:01:45.474375 osafntfd [464:ntfs_imcnutil.c:0130] <<
wait_imcnproc_termination: rc = -1, retry_cnt = 101
Dec 7 11:01:45.474387 osafntfd [464:ntfs_imcnutil.c:0168] TR Normal
termination failed. Escalate to abort
Dec 7 11:01:45.574703 osafntfd [464:ntfs_imcnutil.c:0172] TR Imcn
successfully aborted
Dec 7 11:01:45.574712 osafntfd [464:ntfs_imcnutil.c:0187] <<
timedwait_imcn_exit
~~~
---
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.------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, SlashDot.org! http://sdm.link/slashdot
_______________________________________________
Opensaf-tickets mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/opensaf-tickets
