[Iaxclient-devel] Missing Inbound Calls / Multiple Protocols

SourceForge Headquarters 225 Broadway Suite 1600 San Diego, CA 92101 +1 (858) 422-6466

I just discovered something interesting.  I have my client now working
with multiple registrations and I have found that while the system will
reliably start missing calls (not seeing inbound calls) from my Asterisk
server (CVS updated yesterday) it does not ever seem to miss calls
coming from Iaxtel.

I hope that somebody out there can read the trace from the IAX2
debugging better than I.  Below are two traces.  The first is a call
that failed made from the Grandstream BT101 SIP phone to the IAX client
softphone.  When the call was made, the Grandstream never played back
ringback tones (it was completely silent for about 30 seconds) then give
me a "403" and played about 3 seconds of busy before returning to idle.

The second trace is of a call made from the same phone to the same IAX
Client softphone but by calling its IAXtel number.  As expected, the
call went through with all of the normal functions (ringback on the
BT101, ringing on the softphone) and the call was successfully
completed.

Should I post this to the asterisk-dev list as well?  It seems very
strange that calls coming from the local server would fail, but from the
remote server would succeed.  Is there a patch to IAX2 that has not yet
been applied to the CVS?

Question:  I have the iaxClient library compiled into two DLLs (IAX1 &
IAX2).  My client currently uses either one or the other.  Is there any
foreseeable problem using BOTH?  I want to allow calls to/from a
particular server to be made using IAX1, while calls to/from another
server will use IAX2.  Does that make sense?  Do you see any terrible
issues with this?

Thanks!

Steven

[FALIED CALL: SIP Phone to IAX Client Softphone]

sip*CLI>
    -- Executing Dial("SIP/1101-ac5c", "IAX2/1105|30") in new stack
    -- Called 1105
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
NEW
   Timestamp: 00001ms  SCall: 00005  DCall: 00000 [64.151.42.28:4569]
   VERSION         : 2
   CALLED NUMBER   : s
   CALLING NUMBER  : 1101
   CALLING NAME    : Steven Sokol
   LANGUAGE        : en
   FORMAT          : 2
   CAPABILITY      : 2
   ADSICPE         : 2
   DATE TIME       : 136803348

Rx-Frame Retry[No] -- OSeqno: 000 ISeqno: 002 Type: IAX     Subclass:
ACK
   Timestamp: 00001ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Tx-Frame Retry[001] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
NEW
   Timestamp: 00001ms  SCall: 00005  DCall: 00000 [64.151.42.28:4569]
   VERSION         : 2
   CALLED NUMBER   : s
   CALLING NUMBER  : 1101
   CALLING NAME    : Steven Sokol
   LANGUAGE        : en
   FORMAT          : 2
   CAPABILITY      : 2
   ADSICPE         : 2
   DATE TIME       : 136803348

Rx-Frame Retry[No] -- OSeqno: 000 ISeqno: 002 Type: IAX     Subclass:
ACK
   Timestamp: 00001ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 000 Type: IAX     Subclass:
LAGRQ
   Timestamp: 10012ms  SCall: 00005  DCall: 03540 [64.151.42.28:4569]
Rx-Frame Retry[No] -- OSeqno: 000 ISeqno: 002 Type: IAX     Subclass:
ACK
   Timestamp: 10012ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 000 Type: IAX     Subclass:
PING
   Timestamp: 20012ms  SCall: 00005  DCall: 03540 [64.151.42.28:4569]
Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 000 Type: IAX     Subclass:
LAGRQ
   Timestamp: 20013ms  SCall: 00005  DCall: 03540 [64.151.42.28:4569]
Rx-Frame Retry[No] -- OSeqno: 000 ISeqno: 003 Type: IAX     Subclass:
ACK
   Timestamp: 20012ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Rx-Frame Retry[No] -- OSeqno: 002 ISeqno: 003 Type: IAX     Subclass:
PONG
   Timestamp: 20012ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
VNAK
   Timestamp: 20018ms  SCall: 00005  DCall: 03540 [64.151.42.28:4569]
Rx-Frame Retry[No] -- OSeqno: 000 ISeqno: 004 Type: IAX     Subclass:
ACK
   Timestamp: 20013ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Rx-Frame Retry[No] -- OSeqno: 003 ISeqno: 004 Type: IAX     Subclass:
LAGRP
   Timestamp: 20013ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
VNAK
   Timestamp: 20019ms  SCall: 00005  DCall: 03540 [64.151.42.28:4569]
Rx-Frame Retry[Yes] -- OSeqno: 002 ISeqno: 003 Type: IAX     Subclass:
PONG
   Timestamp: 20012ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
VNAK
   Timestamp: 20076ms  SCall: 00005  DCall: 03540 [64.151.42.28:4569]
Rx-Frame Retry[Yes] -- OSeqno: 003 ISeqno: 004 Type: IAX     Subclass:
LAGRP
   Timestamp: 20013ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
VNAK
   Timestamp: 20077ms  SCall: 00005  DCall: 03540 [64.151.42.28:4569]
Rx-Frame Retry[Yes] -- OSeqno: 002 ISeqno: 003 Type: IAX     Subclass:
PONG
   Timestamp: 20012ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
VNAK
   Timestamp: 20328ms  SCall: 00005  DCall: 03540 [64.151.42.28:4569]
Rx-Frame Retry[Yes] -- OSeqno: 003 ISeqno: 004 Type: IAX     Subclass:
LAGRP
   Timestamp: 20013ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
VNAK
   Timestamp: 20329ms  SCall: 00005  DCall: 03540 [64.151.42.28:4569]
Rx-Frame Retry[Yes] -- OSeqno: 002 ISeqno: 003 Type: IAX     Subclass:
PONG
   Timestamp: 20012ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
VNAK
   Timestamp: 21295ms  SCall: 00005  DCall: 03540 [64.151.42.28:4569]
Rx-Frame Retry[Yes] -- OSeqno: 003 ISeqno: 004 Type: IAX     Subclass:
LAGRP
   Timestamp: 20013ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
VNAK
   Timestamp: 21296ms  SCall: 00005  DCall: 03540 [64.151.42.28:4569]
Rx-Frame Retry[Yes] -- OSeqno: 002 ISeqno: 003 Type: IAX     Subclass:
PONG
   Timestamp: 20012ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
VNAK
   Timestamp: 25139ms  SCall: 00005  DCall: 03540 [64.151.42.28:4569]
Rx-Frame Retry[Yes] -- OSeqno: 003 ISeqno: 004 Type: IAX     Subclass:
LAGRP
   Timestamp: 20013ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
VNAK
   Timestamp: 25140ms  SCall: 00005  DCall: 03540 [64.151.42.28:4569]
    -- Nobody picked up in 30000 ms
    -- Hungup 'IAX2[1105]/5'
Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 000 Type: IAX     Subclass:
HANGUP
   Timestamp: 29993ms  SCall: 00005  DCall: 03540 [64.151.42.28:4569]
Rx-Frame Retry[No] -- OSeqno: 000 ISeqno: 005 Type: IAX     Subclass:
ACK
   Timestamp: 29993ms  SCall: 03540  DCall: 00005 [64.151.42.28:4569]
Rx-Frame Retry[No] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
REGREQ
   Timestamp: 00001ms  SCall: 03557  DCall: 00000 [64.151.42.28:4569]
   USERNAME        : 1105
   REFRESH         : 300

[SUCCESSFUL CALL FROM IAXCOM (Using The Same SIP Phone)]

    -- Executing Dial("SIP/1101-29f4",
"IAX2/ssokol01:ham...@ia.../17008221807@iaxtel") in new stack
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
NEW
   Timestamp: 00001ms  SCall: 00001  DCall: 00000 [69.73.19.178:4569]
   VERSION         : 2
   CALLED NUMBER   : 17008221807
   CALLING NUMBER  : 1101
   CALLING NAME    : Steven Sokol
   LANGUAGE        : en
   CALLED CONTEXT  : iaxtel
   USERNAME        : ssokol01
   FORMAT          : 2
   CAPABILITY      : 2
   ADSICPE         : 2
   DATE TIME       : 136803677

    -- Called ssokol01:ham...@ia.../17008221807@iaxtel
Rx-Frame Retry[No] -- OSeqno: 000 ISeqno: 001 Type: IAX     Subclass:
AUTHREQ
   Timestamp: 00001ms  SCall: 00139  DCall: 00001 [69.73.19.178:4569]
   AUTHMETHODS     : 3
   CHALLENGE       : 224537503
   USERNAME        : ssokol01

Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: IAX     Subclass:
AUTHREP
   Timestamp: 00053ms  SCall: 00001  DCall: 00139 [69.73.19.178:4569]
   MD5 RESULT      : 30c53c657e2aa944ef8f3654e55ff574

Rx-Frame Retry[No] -- OSeqno: 001 ISeqno: 002 Type: IAX     Subclass:
ACCEPT
   Timestamp: 00051ms  SCall: 00139  DCall: 00001 [69.73.19.178:4569]
   FORMAT          : 2

    -- Call accepted by 69.73.19.178 (format GSM)
    -- Format for call is GSM
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 002 Type: IAX     Subclass:
ACK
   Timestamp: 00051ms  SCall: 00001  DCall: 00139 [69.73.19.178:4569]
Rx-Frame Retry[No] -- OSeqno: 002 ISeqno: 002 Type: CONTROL Subclass:
(255?)
   Timestamp: 00054ms  SCall: 00139  DCall: 00001 [69.73.19.178:4569]
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 003 Type: IAX     Subclass:
ACK
   Timestamp: 00054ms  SCall: 00001  DCall: 00139 [69.73.19.178:4569]
    -- IAX2[69.73.19.178:4569]/1 stopped sounds
Rx-Frame Retry[No] -- OSeqno: 003 ISeqno: 002 Type: CONTROL Subclass:
RINGING
   Timestamp: 00139ms  SCall: 00139  DCall: 00001 [69.73.19.178:4569]
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 004 Type: IAX     Subclass:
ACK
   Timestamp: 00139ms  SCall: 00001  DCall: 00139 [69.73.19.178:4569]
    -- IAX2[69.73.19.178:4569]/1 is ringing
Rx-Frame Retry[No] -- OSeqno: 004 ISeqno: 002 Type: CONTROL Subclass:
(255?)
   Timestamp: 03651ms  SCall: 00139  DCall: 00001 [69.73.19.178:4569]
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 005 Type: IAX     Subclass:
ACK
   Timestamp: 03651ms  SCall: 00001  DCall: 00139 [69.73.19.178:4569]
Rx-Frame Retry[No] -- OSeqno: 005 ISeqno: 002 Type: CONTROL Subclass:
ANSWER
   Timestamp: 03652ms  SCall: 00139  DCall: 00001 [69.73.19.178:4569]
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 006 Type: IAX     Subclass:
ACK
   Timestamp: 03652ms  SCall: 00001  DCall: 00139 [69.73.19.178:4569]
Rx-Frame Retry[No] -- OSeqno: 006 ISeqno: 002 Type: IAX     Subclass:
TXREQ
   Timestamp: 03653ms  SCall: 00139  DCall: 00001 [69.73.19.178:4569]
   APPARENT ADDRES : IPV4 64.151.42.28:4569
   CALL NUMBER     : 3585
   TRANSFER ID     : 439399019

Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 007 Type: IAX     Subclass:
ACK
   Timestamp: 03653ms  SCall: 00001  DCall: 00139 [69.73.19.178:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX     Subclass:
TXCNT
   Timestamp: 03705ms  SCall: 00001  DCall: 03585 [64.151.42.28:4569]
   TRANSFER ID     : 439399019

    -- IAX2[69.73.19.178:4569]/1 stopped sounds
    -- IAX2[69.73.19.178:4569]/1 answered SIP/1101-29f4
Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 007 Type: VOICE   Subclass: 2
   Timestamp: 03723ms  SCall: 00001  DCall: 00139 [69.73.19.178:4569]
Rx-Frame Retry[No] -- OSeqno: 007 ISeqno: 002 Type: VOICE   Subclass: 2
   Timestamp: 03679ms  SCall: 00139  DCall: 00001 [69.73.19.178:4569]
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 008 Type: IAX     Subclass:
ACK
   Timestamp: 03679ms  SCall: 00001  DCall: 00139 [69.73.19.178:4569]
Rx-Frame Retry[No] -- OSeqno: 007 ISeqno: 003 Type: IAX     Subclass:
ACK
   Timestamp: 03723ms  SCall: 00139  DCall: 00001 [69.73.19.178:4569]
Rx-Frame Retry[No] -- OSeqno: 008 ISeqno: 003 Type: IAX     Subclass:
HANGUP
   Timestamp: 04915ms  SCall: 00139  DCall: 00001 [69.73.19.178:4569]
Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 009 Type: IAX     Subclass:
ACK
   Timestamp: 04915ms  SCall: 00001  DCall: 00139 [69.73.19.178:4569]
    -- Hungup 'IAX2[69.73.19.178:4569]/1'
  == Spawn extension (default, 917008221807, 1) exited non-zero on
'SIP/1101-29f4'
sip*CLI>