[asterisk-bugs] [JIRA] (ASTERISK-28306) res_pjsip_mwi: MWI NOTIFY occasionally takes minutes to be sent

[Jared Hull (JIRA)]

Jared Hull created ASTERISK-28306:
-------------------------------------

             Summary: res_pjsip_mwi: MWI NOTIFY occasionally takes minutes to be sent
                 Key: ASTERISK-28306
                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-28306
             Project: Asterisk
          Issue Type: Bug
      Security Level: None
          Components: Applications/app_voicemail, Resources/res_pjsip_mwi
    Affects Versions: 16.2.0
            Reporter: Jared Hull
         Attachments: voicemail_send.txt

I am dialing *0103 from extension 103 to leave a voicemail message for extension 103. In the attached voicemail_send.txt, it takes 4 minutes from the time I hang up the phone to the time the MWI NOTIFY packet is sent. Sometimes it is near instant for 10 calls in a row, sometimes it only takes a minute, occasionally it takes too long for my customer's liking.

Log starts when the call is made.
Line 1402 - The call is hung up.
{noformat}[Feb 25 22:52:21] VERBOSE[15281]{noformat}

Line 2126 - MessageWaiting AMI event
{noformat}[Feb 25 22:52:28] DEBUG[15278]{noformat}

Line 2514 - The voicemail.conf externnotify script is executed for the first time. This executes asterisk -rx "devstate change Custom:vm103 BUSY"
{noformat}[Feb 25 22:52:28] DEBUG[15363] app_voicemail.c: Executing sh /voipprovider_scripts/voicemail_notify.sh "" 103 at voicemail 1 0 0 &
{noformat}

Line 2842 - Another MessageWaiting AMI event is sent, the voicemail.conf externnotify script is executed again?, channels soft hangup, and the hangup handler begins. Watching the dialplan in the CLI, it is very noticeable that there is a 10 second delay from the time I hang up the phone to the time that the hangup handler begins. This short delay happens every time on Asterisk 16.2 and I don't recall it on 14.6, but it only happens after voicemail() has actually recorded a voicemail so maybe there is just a bit of latency when writing the voicemail to our NAS which in this case is 38ms away in another datacenter. This delay is not in itself impactful and may or may not be related to the (occasionally) very slow NOTIFYs that I am seeing.
{noformat}[Feb 25 22:52:32] DEBUG[15902][C-00000002] app_voicemail.c: Queueing event for mailbox 103 at voicemail  New: 1   Old: 0
{noformat}

Line 26289 - The NOTIFY is finally sent to the phone, nearly 4 minutes later.
{noformat}[Feb 25 22:56:11] VERBOSE[15283]{noformat}



--
This message was sent by Atlassian JIRA
(v6.2#6252)