[asterisk-bugs] [JIRA] (ASTERISK-27987) AGI() call causes RTP to briefly freeze under certain circumstances

[xrobau (JIRA)]

    [ https://issues.asterisk.org/jira/browse/ASTERISK-27987?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=244309#comment-244309 ] 

xrobau commented on ASTERISK-27987:
-----------------------------------

Thanks Josh! Your suggestion to use Dahdi timing has proved, beyond a shadow of a doubt, that timerfd is the problem.

When I added the following lines to modules.conf, even though the AGI execution rate slowed down, there were no audio glitches present:

{code}
noload = res_timing_timerfd.so
noload = res_timing_kqueue.so
{code}

{code}
[root at freepbx asterisk]# asterisk -rx 'timing test'
Attempting to test a timer with 50 ticks per second.
Using the 'DAHDI' timing module for this test.
It has been 1000 milliseconds, and we got 50 timer ticks
[root at freepbx asterisk]#
{code}

The timing is no longer as accurate (as soon as there is any load on the machine, the time varies by up to +50msec), but the audio is still perfect.

As per our discussions on IRC, I believe we're both in agreement that the actual execve() system call is blocking the poll() on timerfd from returning. This causes the audio glitch because all of the tasks mentioned in this ticket are reliant on timerfd returning accurately.

As I can reasonably reliably replicate this, I'm going to switch back to running this on a VM, so it is easier and faster to manage. Assuming I can still replicate this in a VM, my next test is to replicate this on a newer OS (Ubuntu 18) and see if this is something that is already fixed.


> AGI() call causes RTP to briefly freeze under certain circumstances
> -------------------------------------------------------------------
>
>                 Key: ASTERISK-27987
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-27987
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Core/Bridging
>    Affects Versions: 15.5.0
>            Reporter: xrobau
>            Assignee: Unassigned
>              Labels: patch, pjsip
>         Attachments: agi-time.diff, broken.pcap, debug-server.txt, fdlist.txt, pcap1.png, pcap2.png, timer_list.txt
>
>
> "Something" causes Asterisk to get into a state where launching an AGI causes the entire process to freeze briefly.
> The symptoms are identical to ASTERISK-26257, but that is inaccurate as to the number of services that are impacted.
> Currently I am unable to create an artificial reproduction of the CAUSE, but the symptoms are extremely obvious.
> When Asterisk gets into this state (however it may occur) anything that is reading audio from the filesystem (MoH, Playback()/Background(), or Voicemail) OR confbridge conferences (not meetme) will briefly pause while an AGI is launched.
> We have numerous wireshark captures that show this happening (which we can attach if required), and the timestamps as generated by Asterisk are correct for when the packet WAS sent, not for when it SHOULD have been sent.
> This is triggered by AGI calls in dialplan.  Our test dialplan to determine if Asterisk is in this state is as follows:
> {code}
> exten => 998,1,Answer
>  same => n,Dial(Local/999 at from-internal-custom/n,300,gm(default))
>  same => n,Playback(beep)
>  same => n,Goto(1)
> exten => 999,1,Set(COUNT=0)
>  same => n(loop),GotoIf($[ ${COUNT} > 1000 ]?toomany)
>  same => n,Gosub(testtrigger)
>  same => n,Set(COUNT=$[ ${COUNT} + 1 ])
>  same => n,Goto(loop)
>  same => n(toomany),Hangup
>  same => n(testtrigger),AGI(/bin/true)
>  same => n,Return
> {code}
> If Asterisk is in this broken state, the MoH will be extremely choppy.  After a restart of Asterisk, the MoH is not interrupted.
> We've also noticed that the loop runs MUCH slower when Asterisk is in this state. 
> My random, and probably incorrect, hypothesis is that there's a core lock somewhere that is being grabbed by res_agi which is appending to a gradually growing list, or SOMETHING, that takes a longer and longer time, until it's locking up for longer than 20msec and blocking things that are reading from files (and whatever confbridge is doing)
> I ran that dialplan on a test machine, and was unable to get Asterisk into that state after 250,000 AGI calls. However, our (Sangoma)'s main PBX does randomly and sporadically experience this problem, and we've just got into the habit of restarting asterisk whenever we notice it, which has never been below 30,000 calls (calls as reported by 'core show calls'), and is almost certain to be in that state over 50,000 calls.
> The only common factor that is visible, so far, is that this only happens on Hardware, not in VMs (which may be a red herring), and that all the machines have a lot of listeners to AMI Events.
> Unfortunately, without any way to reproduce this, I'm aware that it's hard to proceed further. However, if there's any more information I can provide when a machine IS in this state, as to what may be causing it, please feel free to ask. 
> Fixing it, as above, is as simple as 'core restart now'. The AGI loops runs fast, and the audio glitch vanishes.



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