[Asterisk-Users] IAX problem - Bug or Compatibility issue?

Aryanto Rachmad aryanto.rachmad at chello.at
Fri Dec 30 10:38:43 MST 2005


Hello All,

I am looking for more thorough debug than the one provided by the command "iax2 debug". Could anybody point me a good documentation about this?

I have a issue with IAX connection. Sometimes it stucked. If so, I have to restart my asterisk through CLI command "restart now".

Comparing the debug messages of working and non working sequences, I have noticed that when it does not work, the following debug messages are missing:

Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: CONTROL Subclass: (14?)
   Timestamp: 01581ms  SCall: 00052  DCall: 16385 [213.61.187.157:4569]
Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 003 Type: IAX     Subclass: ACK
   Timestamp: 01581ms  SCall: 16385  DCall: 00052 [213.61.187.157:4569]
    -- IAX2/sipdiscount_outbound-16385 is making progress passing it to Zap/1-1
Dec 30 17:12:31 DEBUG[12600]: chan_zap.c:4791 zt_indicate: Requested indication 14 on channel Zap/1-1
Dec 30 17:12:31 DEBUG[12600]: chan_zap.c:4857 zt_indicate: Received AST_CONTROL_PROGRESS on Zap/1-1
Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 003 Type: VOICE   Subclass: 4
   Timestamp: 01732ms  SCall: 00052  DCall: 16385 [213.61.187.157:4569]
Dec 30 17:12:31 DEBUG[12569]: chan_iax2.c:6653 socket_read: Ooh, voice format changed to 4
Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 004 Type: IAX     Subclass: ACK
   Timestamp: 01732ms  SCall: 16385  DCall: 00052 [213.61.187.157:4569]

I have a few questions, especially about the following message:
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: CONTROL Subclass: (14?)

1. Is the number 14 in (14?), in decimal or hexadecimal?
2. If that is in decimal, why is it not translated into its descriptions, i.e. Call Progress, according to the IAX2 protocol document I have (Internet-Draft, Expires: July 5, 2005).
3. Why is that number question marked? Is it because asterisk was not sure?
4. If asterisk was not sure, so sometimes it decodes the message sometimes it could not, is there any debug to confirm this?

Or, am I looking at the wrong place? Which maybe the problem is so obvious and I missed that?

I am running asterisk on IBM xSeries 330 with the following detail:
CLI> show version
Asterisk 1.2.1 built by root @ atvie-asterisk on a i686 running Linux on 2005-12-28 07:52:36 UTC
# uname -a
Linux atvie-asterisk 2.6.14-1.1653_FC4smp #1 SMP Tue Dec 13 21:46:01 EST 2005 i686 i686 i386 GNU/Linux

Please find also below the detail of IAX debug messages.

Cheers,

Anto
----

------------------------------------------------------------------------------------------------------------------------
MESSAGES WHEN IAX DOES NOT WORK
------------------------------------------------------------------------------------------------------------------------
    -- Call accepted by 213.61.187.147 (format ulaw)
    -- Format for call is ulaw
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 002 Type: IAX     Subclass: ACK
   Timestamp: 00057ms  SCall: 16384  DCall: 00070 [213.61.187.147:4569]
Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 002 Type: VOICE   Subclass: 4
   Timestamp: 00080ms  SCall: 16384  DCall: 00070 [213.61.187.147:4569]
Dec 30 17:04:25 DEBUG[12488]: chan_iax2.c:3699 find_tpeer: Created trunk peer for '213.61.187.147:4569'
Dec 30 17:04:25 DEBUG[12488]: chan_iax2.c:3725 iax2_trunk_queue: Expanded trunk '213.61.187.147:4569' to 6400 bytes
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: IAX     Subclass: ACK
   Timestamp: 00080ms  SCall: 00070  DCall: 16384 [213.61.187.147:4569]
                                                                               <------- Some messages are missing here
Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 002 Type: IAX     Subclass: LAGRQ
   Timestamp: 10008ms  SCall: 16384  DCall: 00070 [213.61.187.147:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: IAX     Subclass: LAGRQ
   Timestamp: 10016ms  SCall: 00070  DCall: 16384 [213.61.187.147:4569]
Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 003 Type: IAX     Subclass: LAGRP
   Timestamp: 10016ms  SCall: 16384  DCall: 00070 [213.61.187.147:4569]
Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 004 Type: IAX     Subclass: LAGRP
   Timestamp: 10008ms  SCall: 00070  DCall: 16384 [213.61.187.147:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 004 Type: IAX     Subclass: ACK
   Timestamp: 10008ms  SCall: 16384  DCall: 00070 [213.61.187.147:4569]
Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 005 Type: IAX     Subclass: ACK
   Timestamp: 10016ms  SCall: 00070  DCall: 16384 [213.61.187.147:4569]
Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 005 Type: IAX     Subclass: HANGUP
   Timestamp: 10262ms  SCall: 00070  DCall: 16384 [213.61.187.147:4569]
   CAUSE CODE      : 0
------------------------------------------------------------------------------------------------------------------------


------------------------------------------------------------------------------------------------------------------------
MESSAGES AFTER ISSUING "CLI> restart now" command
------------------------------------------------------------------------------------------------------------------------
    -- Call accepted by 213.61.187.157 (format ulaw)
    -- Format for call is ulaw
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 002 Type: IAX     Subclass: ACK
   Timestamp: 00040ms  SCall: 16385  DCall: 00052 [213.61.187.157:4569]
Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 002 Type: VOICE   Subclass: 4
   Timestamp: 00100ms  SCall: 16385  DCall: 00052 [213.61.187.157:4569]
Dec 30 17:12:30 DEBUG[12600]: chan_iax2.c:3699 find_tpeer: Created trunk peer for '213.61.187.157:4569'
Dec 30 17:12:30 DEBUG[12600]: chan_iax2.c:3725 iax2_trunk_queue: Expanded trunk '213.61.187.157:4569' to 6400 bytes
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: IAX     Subclass: ACK
   Timestamp: 00100ms  SCall: 00052  DCall: 16385 [213.61.187.157:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: CONTROL Subclass: (14?)
   Timestamp: 01581ms  SCall: 00052  DCall: 16385 [213.61.187.157:4569]
Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 003 Type: IAX     Subclass: ACK
   Timestamp: 01581ms  SCall: 16385  DCall: 00052 [213.61.187.157:4569]
    -- IAX2/sipdiscount_outbound-16385 is making progress passing it to Zap/1-1
Dec 30 17:12:31 DEBUG[12600]: chan_zap.c:4791 zt_indicate: Requested indication 14 on channel Zap/1-1
Dec 30 17:12:31 DEBUG[12600]: chan_zap.c:4857 zt_indicate: Received AST_CONTROL_PROGRESS on Zap/1-1
Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 003 Type: VOICE   Subclass: 4
   Timestamp: 01732ms  SCall: 00052  DCall: 16385 [213.61.187.157:4569]
Dec 30 17:12:31 DEBUG[12569]: chan_iax2.c:6653 socket_read: Ooh, voice format changed to 4
Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 004 Type: IAX     Subclass: ACK
   Timestamp: 01732ms  SCall: 16385  DCall: 00052 [213.61.187.157:4569]
Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 004 Type: IAX     Subclass: LAGRQ
   Timestamp: 10029ms  SCall: 16385  DCall: 00052 [213.61.187.157:4569]
Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 003 Type: IAX     Subclass: LAGRQ
   Timestamp: 10007ms  SCall: 00052  DCall: 16385 [213.61.187.157:4569]
Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 005 Type: IAX     Subclass: LAGRP
   Timestamp: 10007ms  SCall: 16385  DCall: 00052 [213.61.187.157:4569]
Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 004 Type: IAX     Subclass: LAGRP
   Timestamp: 10029ms  SCall: 00052  DCall: 16385 [213.61.187.157:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 006 Type: IAX     Subclass: ACK
   Timestamp: 10029ms  SCall: 16385  DCall: 00052 [213.61.187.157:4569]
Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 005 Type: IAX     Subclass: ACK
   Timestamp: 10007ms  SCall: 00052  DCall: 16385 [213.61.187.157:4569]
Tx-Frame Retry[000] -- OSeqno: 005 ISeqno: 006 Type: IAX     Subclass: PING
   Timestamp: 20032ms  SCall: 16385  DCall: 00052 [213.61.187.157:4569]
Tx-Frame Retry[000] -- OSeqno: 006 ISeqno: 006 Type: IAX     Subclass: LAGRQ
   Timestamp: 20035ms  SCall: 16385  DCall: 00052 [213.61.187.157:4569]
Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 005 Type: IAX     Subclass: PING
   Timestamp: 20042ms  SCall: 00052  DCall: 16385 [213.61.187.157:4569]
Tx-Frame Retry[000] -- OSeqno: 007 ISeqno: 007 Type: IAX     Subclass: PONG
   Timestamp: 20042ms  SCall: 16385  DCall: 00052 [213.61.187.157:4569]
   RR_JITTER       : 0
   RR_LOSS         : 0
   RR_PKTS         : 1
   RR_DELAY        : 40
   RR_DROPPED      : 0
   RR_OUTOFORDER   : 0
------------------------------------------------------------------------------------------------------------------------
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.digium.com/pipermail/asterisk-users/attachments/20051230/55fddef1/attachment.htm


More information about the asterisk-users mailing list