[asterisk-users] Odd queue issue

[Matt]

Hi,
I have 2 systems (A and B).  I have an 800 number... when someone
calls the 800 number it goes:

IAX2-->A---IAX---B--->SIP PHONE

However.. if the user calling the 800 number is a SIP user that is
registered to A it goes:
SIP--->A---IAX---B--->SIP PHONE

This is the problem... when a call comes in from the IAX2 800
provider, things work fine... however if a SIP user registered to
server A dials the 800 number I have it go directly to server B with:

extensions_custom.conf:exten => 18666111111,1,Dial(IAX2/callcenter/8666111111)

This is what I get in the logs for the failed call:
Dec  4 10:01:41 VERBOSE[14045] logger.c:     -- Called 126
Dec  4 10:01:41 VERBOSE[14008] logger.c:     -- Agent/9999 is ringing
Dec  4 10:01:43 DEBUG[15071] chan_sip.c: Auto destroying call
'af65894e0e2728232031b9cf3bf39110 at 172.16.1.147'
Dec  4 10:01:48 DEBUG[15071] chan_sip.c: Auto destroying call
'570b281a1e1a00776e19975b59d8764f at 172.16.1.120'
Dec  4 10:01:48 WARNING[15071] chan_sip.c: Maximum retries exceeded on
transmission 1307229403c7ba351483327949372537 at 63.174.244.175 for seqno
102 (Critical Request)
Dec  4 10:01:48 WARNING[15071] chan_sip.c: Hanging up call
1307229403c7ba351483327949372537 at 63.174.244.175 - no reply to our
critical packet.
Dec  4 10:01:48 DEBUG[14045] chan_sip.c: update_call_counter(126) -
decrement call limit counter
Dec  4 10:01:48 VERBOSE[14045] logger.c:   == Everyone is
busy/congested at this time (1:0/0/1)
Dec  4 10:01:48 DEBUG[14008] app_queue.c: Dunno what to do with control type -1
Dec  4 10:01:48 DEBUG[14045] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
Dec  4 10:01:48 DEBUG[14045] pbx.c: Expression result is '1'
Dec  4 10:01:48 VERBOSE[14045] logger.c:     -- Executing
GotoIf("Local/126 at default-35d0,2", "1?s-CHANUNAVAIL|1") in new stack
Dec  4 10:01:48 VERBOSE[14045] logger.c:     -- Goto
(macro-exten-vm,s-CHANUNAVAIL,1)
Dec  4 10:01:48 VERBOSE[14045] logger.c:     -- Executing
Congestion("Local/126 at default-35d0,2", "") in new stack
Dec  4 10:01:48 VERBOSE[14008] logger.c:     -- Agent/9999 is circuit-busy
Dec  4 10:01:48 DEBUG[14008] chan_agent.c: Hangup called for state Down
Dec  4 10:01:48 DEBUG[14008] chan_agent.c: Hungup, howlong is 7,
autologoff is 28
Dec  4 10:01:48 DEBUG[14008] app_queue.c: Everyone is busy at this time
Dec  4 10:01:48 VERBOSE[14045] logger.c:   == Spawn extension
(macro-exten-vm, s-CHANUNAVAIL, 1) exited non-zero on
'Local/126 at default-35d0,2' in macro 'exten-vm'


Extention 126 is indeed my phone... and my agent ID is 9999.
If I call in from the IAX2 provider from outside the system I get:
Dec  4 10:06:43 VERBOSE[14214] logger.c:     -- Called 126
Dec  4 10:06:43 VERBOSE[14197] logger.c:     -- Agent/9999 is ringing
Dec  4 10:06:43 DEBUG[15071] chan_sip.c: Auto destroying call
'570b281a1e1a00776e19975b59d8764f at 172.16.1.120'
Dec  4 10:06:43 DEBUG[15071] chan_sip.c: (Provisional) Stopping
retransmission (but retaining packet) on
'4afdb9655ced38f37587d9c50485114e at 63.174.244.175' Request 102: Found
Dec  4 10:06:43 DEBUG[15071] chan_sip.c: (Provisional) Stopping
retransmission (but retaining packet) on
'4afdb9655ced38f37587d9c50485114e at 63.174.244.175' Request 102: Found
Dec  4 10:06:43 DEBUG[15071] chan_sip.c: (Provisional) Stopping
retransmission (but retaining packet) on
'4afdb9655ced38f37587d9c50485114e at 63.174.244.175' Request 102: Found
Dec  4 10:06:43 VERBOSE[14214] logger.c:     -- SIP/126-7d1b is ringing
Dec  4 10:06:47 VERBOSE[15071] logger.c:     -- Started music on hold,
class 'default', on Zap/1-1
Dec  4 10:06:47 DEBUG[15071] channel.c: Scheduling timer at 160 sample intervals
Dec  4 10:06:47 DEBUG[14188] channel.c: Generator got voice, switching
to phase locked mode
Dec  4 10:06:47 DEBUG[14188] channel.c: Scheduling timer at 0 sample intervals
Dec  4 10:06:47 DEBUG[15071] chan_sip.c: Stopping retransmission on
'610dc50c9daebd7d457a841c39f99190 at 63.174.244.196' of Response
1228778601: Match Found
Dec  4 10:06:47 DEBUG[15071] chan_sip.c: Acked pending invite 102
Dec  4 10:06:47 DEBUG[15071] chan_sip.c: Stopping retransmission on
'4afdb9655ced38f37587d9c50485114e at 63.174.244.175' of Request 102:
Match Found
Dec  4 10:06:47 DEBUG[15071] chan_sip.c: build_route: Contact hop:
<sip:126 at 63.174.244.196>
Dec  4 10:06:47 DEBUG[15059] channel.c: Avoiding initial deadlock for
'SIP/126-7d1b'
Dec  4 10:06:47 VERBOSE[14214] logger.c:     -- SIP/126-7d1b answered
Local/126 at default-3489,2
Dec  4 10:06:47 DEBUG[14197] app_queue.c: Dunno what to do with control type -1
Dec  4 10:06:47 VERBOSE[14197] logger.c:     -- Agent/9999 answered
IAX2/serverA-1
Dec  4 10:06:47 DEBUG[15059] channel.c: Avoiding initial deadlock for
'Local/126 at default-3489,2'
Dec  4 10:06:47 DEBUG[14197] channel.c: Scheduling timer at 160 sample intervals
Dec  4 10:06:47 VERBOSE[14197] logger.c:     -- Playing
'custom/CountDown' (language 'en')
Dec  4 10:06:48 DEBUG[14214] channel.c: Planning to masquerade channel
SIP/126-7d1b into the structure of Local/126 at default-3489,1
Dec  4 10:06:48 DEBUG[14214] channel.c: Done planning to masquerade
channel SIP/126-7d1b into the structure of Local/126 at default-3489,1
Dec  4 10:06:48 DEBUG[14214] chan_local.c: Not posting to queue since
already masked on 'Local/126 at default-3489,2'
Dec  4 10:06:48 DEBUG[14197] channel.c: Got clone lock for masquerade
on 'SIP/126-7d1b' at 0x8cb6554
Dec  4 10:06:48 DEBUG[14197] channel.c: Putting channel SIP/126-7d1b
in 4/4 formats
Dec  4 10:06:48 DEBUG[14197] channel.c: Released clone lock on
'Local/126 at default-3489,1<ZOMBIE>'
Dec  4 10:06:48 DEBUG[14197] channel.c: Done Masquerading SIP/126-7d1b (6)
Dec  4 10:06:48 DEBUG[14197] chan_agent.c: Bridge on 'SIP/126-7d1b'
being set to 'Agent/9999' (3)
Dec  4 10:06:48 DEBUG[14214] channel.c: Didn't get a frame from
channel: Local/126 at default-3489,1<ZOMBIE>
Dec  4 10:06:48 DEBUG[14214] channel.c: Bridge stops bridging channels
Local/126 at default-3489,2 and Local/126 at default-3489,1<ZOMBIE>
Dec  4 10:06:48 DEBUG[14214] app_dial.c: Exiting with DIALSTATUS=ANSWER.

What the heck?  Anyone have an explination?