thr3ads.net - asterisk users - [asterisk-users] IAX Hangup floods link with repeated VNAK and HANGUP [Sep 2008]

If this information is useful, please help other people find it:
Share via:

Nathan Dennis

2008-Sep-24 08:50 UTC

[asterisk-users] IAX Hangup floods link with repeated VNAK and HANGUP

We have been using asterisk for a while now but have recently needed to
install a second server in a remote office and set up a iax trunk
between the 2 servers. The dial plan seems to work well when I tested it
on the same LAN. However this afternoon I connected the system at the
remote office and made some calls. All the calls connect and work fine,
voice quality is great no really couldn't have hoped for better. Hang up
the call and tried to make another call and nothing, the link was not
responding, after much trouble shooting I have found that after the call
is hung up the 2 asterisk servers seem to go into some kind of loop
sending each other message. I have pasted a debug for both servers below
that include everything from the start of the call to after hangup. I
have cut them short at the VNAK and Hangup cycle just continues for
30seconds or so flooding the link completely.
 
Any help you may be able to provide would be greatly appreciated
 
 
IAX Debug on first server
 
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass:
ACK
   Timestamp: 00014ms  SCall: 06840  DCall: 16384 [10.10.51.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass:
AUTHREQ
   Timestamp: 00003ms  SCall: 06840  DCall: 16384 [10.10.51.22:4569]
   AUTHMETHODS     : 3
   CHALLENGE       : 147710225
   USERNAME        : cairns
 
Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass:
AUTHREP
   Timestamp: 00100ms  SCall: 16384  DCall: 06840 [10.10.51.22:4569]
   MD5 RESULT      : 028e5753e0c82ce337ad4ba898a80bcf
 
Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 002 Type: IAX     Subclass:
ACK
   Timestamp: 00100ms  SCall: 06840  DCall: 16384 [10.10.51.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 002 Type: IAX     Subclass:
ACCEPT
   Timestamp: 00088ms  SCall: 06840  DCall: 16384 [10.10.51.22:4569]
   FORMAT          : 256
 
    -- Call accepted by 10.10.51.22 (format g729)
    -- Format for call is g729
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 002 Type: IAX     Subclass:
ACK
   Timestamp: 00088ms  SCall: 16384  DCall: 06840 [10.10.51.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: CONTROL Subclass:
ANSWER
   Timestamp: 00091ms  SCall: 06840  DCall: 16384 [10.10.51.22:4569]
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 003 Type: IAX     Subclass:
ACK
   Timestamp: 00091ms  SCall: 16384  DCall: 06840 [10.10.51.22:4569]
    -- IAX2/brisbane-16384 answered SIP/1406-b7b2b530
Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 002 Type: VOICE   Subclass:
136
   Timestamp: 00100ms  SCall: 06840  DCall: 16384 [10.10.51.22:4569]
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 004 Type: IAX     Subclass:
ACK
   Timestamp: 00100ms  SCall: 16384  DCall: 06840 [10.10.51.22:4569]
Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 004 Type: VOICE   Subclass:
136
   Timestamp: 00288ms  SCall: 16384  DCall: 06840 [10.10.51.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 003 Type: IAX     Subclass:
ACK
   Timestamp: 00288ms  SCall: 06840  DCall: 16384 [10.10.51.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 003 Type: CONTROL Subclass:
(255?)
   Timestamp: 03123ms  SCall: 06840  DCall: 16384 [10.10.51.22:4569]
Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 005 Type: IAX     Subclass:
ACK
   Timestamp: 03123ms  SCall: 16384  DCall: 06840 [10.10.51.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
POKE
   Timestamp: 00005ms  SCall: 08676  DCall: 00000 [10.10.51.22:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass:
PONG
   Timestamp: 00005ms  SCall: 00007  DCall: 08676 [10.10.51.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass:
ACK
   Timestamp: 00005ms  SCall: 08676  DCall: 00007 [10.10.51.22:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
POKE
   Timestamp: 00018ms  SCall: 00001  DCall: 00000 [10.10.51.22:4569]
Rx-Frame Retry[Yes] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
PONG
   Timestamp: 00000ms  SCall: 00001  DCall: 00001 [10.10.51.22:4569]
Tx-Frame Retry[-01] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass:
ACK
   Timestamp: 00078ms  SCall: 00001  DCall: 00001 [10.10.51.22:4569]
Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 005 Type: IAX     Subclass:
LAGRQ
   Timestamp: 10015ms  SCall: 16384  DCall: 06840 [10.10.51.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 004 Type: IAX     Subclass:
LAGRP
   Timestamp: 10015ms  SCall: 06840  DCall: 16384 [10.10.51.22:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 006 Type: IAX     Subclass:
ACK
   Timestamp: 10015ms  SCall: 16384  DCall: 06840 [10.10.51.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 004 Type: IAX     Subclass:
LAGRQ
   Timestamp: 09855ms  SCall: 06840  DCall: 16384 [10.10.51.22:4569]
Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 007 Type: IAX     Subclass:
LAGRP
   Timestamp: 09855ms  SCall: 16384  DCall: 06840 [10.10.51.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 005 Type: IAX     Subclass:
ACK
   Timestamp: 09855ms  SCall: 06840  DCall: 16384 [10.10.51.22:4569]
    -- Hungup 'IAX2/brisbane-16384'
  == Spawn extension (iax2brisbaneout, 5510, 1) exited non-zero on
'SIP/1406-b7b2b530'
    -- Executing [h at iax2brisbaneout:1] Dial("SIP/1406-b7b2b530",
"IAX2/brisbane/h at internal") in new stack
    -- Called brisbane/h at internal
    -- Hungup 'IAX2/brisbane-16385'
Tx-Frame Retry[000] -- OSeqno: 005 ISeqno: 007 Type: IAX     Subclass:
HANGUP
   Timestamp: 16939ms  SCall: 16384  DCall: 06840 [10.10.51.22:4569]
   CAUSE CODE      : 16
 
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
NEW
   Timestamp: 00003ms  SCall: 16385  DCall: 00000 [10.10.51.22:4569]
   VERSION         : 2
   CALLED NUMBER   : h
   CODEC_PREFS     : (g729)
   CALLING NUMBER  : 1406
   CALLING PRESNTN : 0
   CALLING TYPEOFN : 0
   CALLING TRANSIT : 0
   CALLING NAME    : Nathan Dennis
   LANGUAGE        : en
   CALLED CONTEXT  : internal
   USERNAME        : cairns
   FORMAT          : 256
   CAPABILITY      : 57600
   ADSICPE         : 2
   DATE TIME       : 2008-09-24  18:35:44
 
Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 000 Type: IAX     Subclass:
HANGUP
   Timestamp: 00006ms  SCall: 16385  DCall: 00000 [10.10.51.22:4569]
   CAUSE CODE      : 0
 
  == Spawn extension (iax2brisbaneout, h, 1) exited non-zero on
'SIP/1406-b7b2b530'
 Extension Changed 1406[internalhints] new state Idle for Notify User
1401 (queued)
 Extension Changed 1406[internalhints] new state Idle for Notify User
1419 (queued)
 Extension Changed 1406[internalhints] new state Idle for Notify User
1415 (queued)
 Extension Changed 1406[internalhints] new state Idle for Notify User
1402 (queued)
 Extension Changed 1406[internalhints] new state Idle for Notify User
1404 (queued)
 Extension Changed 1406[internalhints] new state Idle for Notify User
1411 (queued)
 Extension Changed 1406[internalhints] new state Idle for Notify User
1408 (queued)
    -- Incoming call: Got SIP response 500 "Internal Server Error"
back
from 10.10.11.193
Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 006 Type: IAX     Subclass:
ACK
   Timestamp: 16939ms  SCall: 06840  DCall: 16384 [10.10.51.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass:
ACK
   Timestamp: 00003ms  SCall: 08602  DCall: 16385 [10.10.51.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass:
AUTHREQ
   Timestamp: 00011ms  SCall: 08602  DCall: 16385 [10.10.51.22:4569]
   AUTHMETHODS     : 3
   CHALLENGE       : 842177371
   USERNAME        : cairns
Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 001 Type: IAX     Subclass:
AUTHREP
   Timestamp: 00116ms  SCall: 16385  DCall: 08602 [10.10.51.22:4569]
   MD5 RESULT      : b9f5616e47f5f8e5605868b717d510aa
 
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
INVAL
   Timestamp: 00000ms  SCall: 00000  DCall: 16385 [10.10.51.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass:
VNAK
   Timestamp: 00118ms  SCall: 08602  DCall: 16385 [10.10.51.22:4569]
Tx-Frame Retry[001] -- OSeqno: 001 ISeqno: 000 Type: IAX     Subclass:
HANGUP
   Timestamp: 00006ms  SCall: 16385  DCall: 00000 [10.10.51.22:4569]
   CAUSE CODE      : 0
 
Tx-Frame Retry[001] -- OSeqno: 002 ISeqno: 001 Type: IAX     Subclass:
AUTHREP
   Timestamp: 00116ms  SCall: 16385  DCall: 08602 [10.10.51.22:4569]
   MD5 RESULT      : b9f5616e47f5f8e5605868b717d510aa
 
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
INVAL
   Timestamp: 00000ms  SCall: 00000  DCall: 16385 [10.10.51.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass:
VNAK
   Timestamp: 00232ms  SCall: 08602  DCall: 16385 [10.10.51.22:4569]
Tx-Frame Retry[001] -- OSeqno: 001 ISeqno: 000 Type: IAX     Subclass:
HANGUP
   Timestamp: 00006ms  SCall: 16385  DCall: 00000 [10.10.51.22:4569]
   CAUSE CODE      : 0

 
 
IAX Debug on second Server
 
Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 002 Type: CONTROL Subclass:
ANSWER
   Timestamp: 00091ms  SCall: 06840  DCall: 16384 [10.10.11.22:4569]
Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 002 Type: VOICE   Subclass:
136
   Timestamp: 00100ms  SCall: 06840  DCall: 16384 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: IAX     Subclass:
ACK
   Timestamp: 00088ms  SCall: 16384  DCall: 06840 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: IAX     Subclass:
ACK
   Timestamp: 00091ms  SCall: 16384  DCall: 06840 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: IAX     Subclass:
ACK
   Timestamp: 00100ms  SCall: 16384  DCall: 06840 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: VOICE   Subclass:
136
   Timestamp: 00288ms  SCall: 16384  DCall: 06840 [10.10.11.22:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 003 Type: IAX     Subclass:
ACK
   Timestamp: 00288ms  SCall: 06840  DCall: 16384 [10.10.11.22:4569]
Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 003 Type: CONTROL Subclass:
(255?)
   Timestamp: 03123ms  SCall: 06840  DCall: 16384 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 005 Type: IAX     Subclass:
ACK
   Timestamp: 03123ms  SCall: 16384  DCall: 06840 [10.10.11.22:4569]
    -- Started music on hold, class 'default', on channel
'IAX2/cairns-6840'
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
POKE
   Timestamp: 00005ms  SCall: 08676  DCall: 00000 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass:
PONG
   Timestamp: 00005ms  SCall: 00007  DCall: 08676 [10.10.11.22:4569]
Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass:
ACK
   Timestamp: 00005ms  SCall: 08676  DCall: 00007 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
POKE
   Timestamp: 00018ms  SCall: 00001  DCall: 00000 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass:
ACK
   Timestamp: 00078ms  SCall: 00001  DCall: 00001 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 005 Type: IAX     Subclass:
LAGRQ
   Timestamp: 10015ms  SCall: 16384  DCall: 06840 [10.10.11.22:4569]
Tx-Frame Retry[000] -- OSeqno: 005 ISeqno: 004 Type: IAX     Subclass:
LAGRP
   Timestamp: 10015ms  SCall: 06840  DCall: 16384 [10.10.11.22:4569]
Tx-Frame Retry[000] -- OSeqno: 006 ISeqno: 004 Type: IAX     Subclass:
LAGRQ
   Timestamp: 09855ms  SCall: 06840  DCall: 16384 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 006 Type: IAX     Subclass:
ACK
   Timestamp: 10015ms  SCall: 16384  DCall: 06840 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 007 Type: IAX     Subclass:
LAGRP
   Timestamp: 09855ms  SCall: 16384  DCall: 06840 [10.10.11.22:4569]
Tx-Frame Retry[-01] -- OSeqno: 007 ISeqno: 005 Type: IAX     Subclass:
ACK
   Timestamp: 09855ms  SCall: 06840  DCall: 16384 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 007 Type: IAX     Subclass:
HANGUP
   Timestamp: 16939ms  SCall: 16384  DCall: 06840 [10.10.11.22:4569]
   CAUSE CODE      : 16
 
Tx-Frame Retry[-01] -- OSeqno: 007 ISeqno: 006 Type: IAX     Subclass:
ACK
   Timestamp: 16939ms  SCall: 06840  DCall: 16384 [10.10.11.22:4569]
    -- Stopped music on hold on IAX2/cairns-6840
    -- Hungup 'Zap/pseudo-167229242'
  == Spawn extension (internal, 5510, 1) exited non-zero on
'IAX2/cairns-6840'
    -- Hungup 'IAX2/cairns-6840'
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
NEW
   Timestamp: 00003ms  SCall: 16385  DCall: 00000 [10.10.11.22:4569]
   VERSION         : 2
   CALLED NUMBER   : h
   CODEC_PREFS     : (g729)
   CALLING NUMBER  : 1406
   CALLING PRESNTN : 0
   CALLING TYPEOFN : 0
   CALLING TRANSIT : 0
   CALLING NAME    : Nathan Dennis
   LANGUAGE        : en
   CALLED CONTEXT  : internal
   USERNAME        : cairns
   FORMAT          : 256
   CAPABILITY      : 57600
   ADSICPE         : 2
   DATE TIME       : 2008-09-24  18:35:44
 
Tx-Frame Retry[-01] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass:
ACK
   Timestamp: 00003ms  SCall: 08602  DCall: 16385 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 000 Type: IAX     Subclass:
HANGUP
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass:
AUTHREQ
   Timestamp: 00006ms  SCall: 16385  DCall: 00000 [10.10.11.22:4569]
   Timestamp: 00011ms  SCall: 08602  DCall: 16385 [10.10.11.22:4569]
   CAUSE CODE      : 0
   AUTHMETHODS     : 3
   CHALLENGE       : 842177371
   USERNAME        : cairns
Tx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
INVAL
   Timestamp: 00000ms  SCall: 00000  DCall: 16385 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 001 Type: IAX     Subclass:
AUTHREP
   Timestamp: 00116ms  SCall: 16385  DCall: 08602 [10.10.11.22:4569]
   MD5 RESULT      : b9f5616e47f5f8e5605868b717d510aa
 
Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass:
VNAK
   Timestamp: 00118ms  SCall: 08602  DCall: 16385 [10.10.11.22:4569]
Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 000 Type: IAX     Subclass:
HANGUP
   Timestamp: 00006ms  SCall: 16385  DCall: 00000 [10.10.11.22:4569]
   CAUSE CODE      : 0
 
 
Regards
Nathan Dennis

Tony Mountifield

2008-Sep-24 10:03 UTC

head link

[asterisk-users] IAX Hangup floods link with repeated VNAK and HANGUP

In article <223CF3DA2BD6E04A848489C110796B7A479D59 at
cnsinsbs1.cairns.i-solutions.net.au>,
Nathan Dennis <Nathan.Dennis at i-solutions.net.au>
wrote:> We have been using asterisk for a while now but have recently needed to
> install a second server in a remote office and set up a iax trunk
> between the 2 servers. The dial plan seems to work well when I tested it
> on the same LAN. However this afternoon I connected the system at the
> remote office and made some calls. All the calls connect and work fine,
> voice quality is great no really couldn't have hoped for better. Hang
up
> the call and tried to make another call and nothing, the link was not
> responding, after much trouble shooting I have found that after the call
> is hung up the 2 asterisk servers seem to go into some kind of loop
> sending each other message. I have pasted a debug for both servers below
> that include everything from the start of the call to after hangup. I
> have cut them short at the VNAK and Hangup cycle just continues for
> 30seconds or so flooding the link completely.
>  
> Any help you may be able to provide would be greatly appreciated
I can't help with your problem, sorry, but anyone who can help will need
to know exactly what version of Asterisk you have at each end.

Cheers
Tony
-- 
Tony Mountifield
Work: tony at softins.co.uk - http://www.softins.co.uk
Play: tony at mountifield.org - http://tony.mountifield.org

asterisk users - Sep 2008 - IAX Hangup floods link with repeated VNAK and HANGUP

[asterisk-users] IAX Hangup floods link with repeated VNAK and HANGUP

[asterisk-users] IAX Hangup floods link with repeated VNAK and HANGUP