[asterisk-bugs] [Asterisk 0010248]: chan_iax2 VNAK storm seen
noreply at bugs.digium.com
noreply at bugs.digium.com
Wed Aug 1 16:59:03 CDT 2007
The following issue has been ASSIGNED.
======================================================================
http://bugs.digium.com/view.php?id=10248
======================================================================
Reported By: stevedavies
Assigned To: russell
======================================================================
Project: Asterisk
Issue ID: 10248
Category: Channels/chan_iax2
Reproducibility: always
Severity: minor
Priority: normal
Status: assigned
Asterisk Version: 1.4.5
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-20-2007 04:47 CDT
Last Modified: 08-01-2007 16:58 CDT
======================================================================
Summary: chan_iax2 VNAK storm seen
Description:
Saw this happening on a customer between two boxes:
Tx-Frame Retry[-01] -- OSeqno: 064 ISeqno: 060 Type: IAX Subclass:
LAGRP
Timestamp: 200069ms SCall: 00061 DCall: 00059 [196.40.106.94:4569]
Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 011 Type: IAX Subclass:
VNAK
Timestamp: 29274ms SCall: 00047 DCall: 00061 [196.40.106.94:4569]
Tx-Frame Retry[-01] -- OSeqno: 064 ISeqno: 060 Type: IAX Subclass:
LAGRP
Timestamp: 200069ms SCall: 00061 DCall: 00059 [196.40.106.94:4569]
Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 011 Type: IAX Subclass:
VNAK
Timestamp: 29285ms SCall: 00047 DCall: 00061 [196.40.106.94:4569]
Tx-Frame Retry[-01] -- OSeqno: 064 ISeqno: 060 Type: IAX Subclass:
LAGRP
Timestamp: 200069ms SCall: 00061 DCall: 00059 [196.40.106.94:4569]
Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 011 Type: IAX Subclass:
VNAK
Timestamp: 29294ms SCall: 00047 DCall: 00061 [196.40.106.94:4569]
Tx-Frame Retry[-01] -- OSeqno: 064 ISeqno: 060 Type: IAX Subclass:
LAGRP
Timestamp: 200069ms SCall: 00061 DCall: 00059 [196.40.106.94:4569]
Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 011 Type: IAX Subclass:
VNAK
Timestamp: 29305ms SCall: 00047 DCall: 00061 [196.40.106.94:4569]
Tx-Frame Retry[-01] -- OSeqno: 064 ISeqno: 060 Type: IAX Subclass:
LAGRP
Timestamp: 200069ms SCall: 00061 DCall: 00059 [196.40.106.94:4569]
Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 011 Type: IAX Subclass:
VNAK
Timestamp: 29314ms SCall: 00047 DCall: 00061 [196.40.106.94:4569]
Tx-Frame Retry[-01] -- OSeqno: 064 ISeqno: 060 Type: IAX Subclass:
LAGRP
Timestamp: 200069ms SCall: 00061 DCall: 00059 [196.40.106.94:4569]
Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 011 Type: IAX Subclass:
VNAK
Timestamp: 29341ms SCall: 00047 DCall: 00061 [196.40.106.94:4569]
Tx-Frame Retry[-01] -- OSeqno: 064 ISeqno: 060 Type: IAX Subclass:
LAGRP
Timestamp: 200069ms SCall: 00061 DCall: 00059 [196.40.106.94:4569]
Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 011 Type: IAX Subclass:
VNAK
Timestamp: 29351ms SCall: 00047 DCall: 00061 [196.40.106.94:4569]
Tx-Frame Retry[-01] -- OSeqno: 064 ISeqno: 060 Type: IAX Subclass:
LAGRP
Timestamp: 200069ms SCall: 00061 DCall: 00059 [196.40.106.94:4569]
Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 011 Type: IAX Subclass:
VNAK
Timestamp: 29360ms SCall: 00047 DCall: 00061 [196.40.106.94:4569]
Tx-Frame Retry[-01] -- OSeqno: 064 ISeqno: 060 Type: IAX Subclass:
LAGRP
Timestamp: 200069ms SCall: 00061 DCall: 00059 [196.40.106.94:4569]
Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 011 Type: IAX Subclass:
VNAK
Timestamp: 29369ms SCall: 00047 DCall: 00061 [196.40.106.94:4569]
Tx-Frame Retry[-01] -- OSeqno: 064 ISeqno: 060 Type: IAX Subclass:
LAGRP
Timestamp: 200069ms SCall: 00061 DCall: 00059 [196.40.106.94:4569]
Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 011 Type: IAX Subclass:
VNAK
Timestamp: 29378ms SCall: 00047 DCall: 00061 [196.40.106.94:4569]
Tx-Frame Retry[-01] -- OSeqno: 064 ISeqno: 060 Type: IAX Subclass:
LAGRP
Timestamp: 200069ms SCall: 00061 DCall: 00059 [196.40.106.94:4569]
Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 011 Type: IAX Subclass:
VNAK
Timestamp: 29387ms SCall: 00047 DCall: 00061 [196.40.106.94:4569]
etc etc etc etc
It did stop eventually when:
Rx-Frame Retry[ No] -- OSeqno: 010 ISeqno: 014 Type: IAX Subclass:
HANGUP
Timestamp: 30238ms SCall: 00047 DCall: 00061 [196.40.106.94:4569]
CAUSE CODE : 0
Tx-Frame Retry[-01] -- OSeqno: 014 ISeqno: 011 Type: IAX Subclass: ACK
Timestamp: 30238ms SCall: 00061 DCall: 00047 [196.40.106.94:4569]
Rx-Frame Retry[ No] -- OSeqno: 014 ISeqno: 014 Type: IAX Subclass:
VNAK
Timestamp: 30245ms SCall: 00047 DCall: 00061 [196.40.106.94:4569]
Tx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass:
INVAL
Timestamp: 00000ms SCall: 00061 DCall: 00047 [196.40.106.94:4569]
======================================================================
----------------------------------------------------------------------
svnbot - 08-01-07 16:58
----------------------------------------------------------------------
Repository: asterisk
Revision: 77887
------------------------------------------------------------------------
r77887 | russell | 2007-08-01 16:58:53 -0500 (Wed, 01 Aug 2007) | 23 lines
Fix some race conditions which have been causing weird problems in
chan_iax2.
The most notable problem is that people have been seeing storms of VNAK
frames
being sent due to really old frames mysteriously being in the
retransmission
queue and never getting removed.
It was possible that a dynamic thread got created, but did not acquire its
lock
before the thread that created it signals it to perform an action. When
this
happens, the thread will sleep until it hits a timeout, and then get
destroyed.
So, the action never gets performed and in some cases, means a frame
doesn't
get transmitted and never gets freed since the scheduler never gets a
chance
to reschedule transmission.
Another less severe race condition is in the handling of a timeout for a
dynamic
thread. It was possible for it to be acquired to perform at action at the
same
time that it hit a timeout. When this occurs, whatever action it was
acquired
for would never get performed.
(patch contributed by Mihai and SteveK)
(closes issue http://bugs.digium.com/view.php?id=10289)
(closes issue http://bugs.digium.com/view.php?id=10248)
(closes issue http://bugs.digium.com/view.php?id=10232)
(possibly related to issue http://bugs.digium.com/view.php?id=10359)
------------------------------------------------------------------------
Issue History
Date Modified Username Field Change
======================================================================
08-01-07 16:58 svnbot Checkin
08-01-07 16:58 svnbot Note Added: 0068255
08-01-07 16:58 svnbot Status feedback => assigned
08-01-07 16:58 svnbot Assigned To => russell
======================================================================
More information about the asterisk-bugs
mailing list