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

Aryanto Rachmad aryanto.rachmad at chello.at
Fri Dec 30 18:05:24 MST 2005


Nevermind. I think I found it. I didn't realise that Ethereal can decode IAX2 protocol.

When IAX does not work, sometimes I got the following message as well:

DEBUG[2213] chan_iax2.c: Immediately destroying 16384, having received INVAL

What else can we say about that a part from my asterisk received frame with INVAL (Invalid call) or in other word incompatible frame?

I also found a very quick and dirty workaround which is enough for me at the moment.
  ----- Original Message ----- 
  From: Aryanto Rachmad 
  To: asterisk-users at lists.digium.com 
  Sent: Friday, December 30, 2005 6:38 PM
  Subject: [Asterisk-Users] IAX problem - Bug or Compatibility issue?


  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
  ------------------------------------------------------------------------------------------------------------------------



------------------------------------------------------------------------------


  _______________________________________________
  --Bandwidth and Colocation provided by Easynews.com --

  Asterisk-Users mailing list
  To UNSUBSCRIBE or update options visit:
     http://lists.digium.com/mailman/listinfo/asterisk-users
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.digium.com/pipermail/asterisk-users/attachments/20051230/17fa6137/attachment.htm


More information about the asterisk-users mailing list