[asterisk-users] IAX Hangup floods link with repeated VNAK and HANGUP
Nathan Dennis
Nathan.Dennis at i-solutions.net.au
Wed Sep 24 03:50:28 CDT 2008
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
More information about the asterisk-users
mailing list