[asterisk-bugs] [Asterisk 0010289]: Old LAGRQ frames showing up in new IAX2 calls

[noreply at bugs.digium.com]

A NOTE has been added to this issue. 
====================================================================== 
http://bugs.digium.com/view.php?id=10289 
====================================================================== 
Reported By:                mihai
Assigned To:                russell
====================================================================== 
Project:                    Asterisk
Issue ID:                   10289
Category:                   Channels/chan_iax2
Reproducibility:            always
Severity:                   minor
Priority:                   normal
Status:                     assigned
Asterisk Version:           1.4.8  
SVN Branch (only for SVN checkouts, not tarball releases): N/A  
SVN Revision (number only!):  
Disclaimer on File?:        N/A 
Request Review:              
====================================================================== 
Date Submitted:             07-24-2007 10:52 CDT
Last Modified:              07-26-2007 20:53 CDT
====================================================================== 
Summary:                    Old LAGRQ frames showing up in new IAX2 calls
Description: 
If there are two successive IAX2 calls having the same source and
destination call id, sometimes old LAGRQ frames belonging to the first call
are transmitted as part of a VNAK retransmission during the second call.
Since the old LAGRQ have wildly out of order sequence numbers, the other
endpoint will request retransmission, which can cause a VNAK storm.
I am able to reproduce this by stress testing chan_iax2 with an automated
script that generates about 3 calls per second, up to about 200
simultaneous calls.  This will pretty much guarantee that source ids will
be recycled on the server side, which can trigger this issue. 
====================================================================== 

---------------------------------------------------------------------- 
 mihai - 07-26-07 20:53  
---------------------------------------------------------------------- 
I've looked into this problem a little bit more and I've found something
interesting: there are a lot of frames in the retransmission queue (iaxq)
that have the retries field set to -1.  If my understanding of the code is
correct, retries is -1 when the frame needs to be cleared up (either
because it was acked, or because the call was terminated, or any other
reason).  Now AFAIK, there are only two places that that clear up frames:
one in attempt_transmit and another in network_thread.  The code in
network_thread is never reached, because the sentyet flag is normally true.
 Which leaves the code in attempt_transmit

Now this is where it gets interesting.  When a frame is scheduled for
retransmission, the scheduler calls attempt_transmit, which in turn decides
whether to remove the frame and free it or just to increment its retries
counter.  The effect of this is that if the frame is marked for deletion
now, it could take as much as MAX_RETRY_TIME (10 sec) before the scheduler
triggers a call to attempt_transmit and give it a chance to remove the
frame. 

This in itself is not such a big deal, however, if something goes wrong
with the scheduler, the frame will never get removed from the queue.  Now
assume that the call is over and after a while, a new call gets assigned to
that slot.  If a VNAK request is made, chances are the queued up frames
will show up and start the VNAK storm. 

I am not saying that this is what happens, since I have not figured out
what goes wrong yet.  All I am saying is that this is a strong possibility,
and matches what we have seen in traces and core dumps. 

Issue History 
Date Modified   Username       Field                    Change               
====================================================================== 
07-26-07 20:53  mihai          Note Added: 0067961                          
======================================================================