asterisk users - Jan 2011 - Really wacky problem with internal extensions.

We have an Asterisk server acting as a hosted PBX system for many clients,
and we're going through an upgrade to Asterisk 1.6 by moving our most
important (and complicated) clients one at a time.

But we're having a problem with one customer that I really can't
explain.

I can place calls directly to one phone at the customer's location (they
also have an IVR that asks for an extension number), but the customer
cannot do the same internally. All other outbound calls from this
customer, work. The dialplans for the IVR and for internal dialing are
very nearly identical, and making them completely identical doesn't change
anything. The dialplans are pasted at the end of this message.

When the customer dials an internal extension, the Asterisk console
produces this output (usernames redacted):

    -- Executing [303 at XXXXXX:1] Set("SIP/XXXXXX2-000004ce",
"CALLERID(name)="Internal call"") in new stack
    -- Executing [303 at XXXXXX:2] GotoIf("SIP/XXXXXX2-000004ce",
"0?dialfw:dial") in new stack
    -- Goto (XXXXXX,303,8)
    -- Executing [303 at XXXXXX:8] Dial("SIP/XXXXXX2-000004ce",
"SIP/XXXXXX3,20,g") in new stack
  == Using SIP RTP CoS mark 5
    -- Called XXXXXX3
    -- Got SIP response 400 "Bad Request" back from 209.53.201.33
    -- SIP/XXXXXX3-000004cf is circuit-busy

Usually this "SIP response 400" error is due to the firewall at the
customer's location blocking the incoming connection, but then why would
normal inbound calls work? It's not like the Dial() command for those
inbound calls is any different. This customer hasn't changed any firewall
rules during the changeover, and is forwarding unique ports for each
phone. Furthermore, the SIP configuration for these phones send a
qualification message every 60 seconds to keep any NAT translation alive.

Anyway, here's the dialplan for the IVR (only extensions 302 and 303 are
included for brevity):

[ivr-XXXXXX]
exten => s,1,Answer
exten => s,n,Playback(silence/1)
exten => s,n,Background(XXXXXX/greeting)
exten => s,n,WaitExten(4)

exten => 302,1,GotoIf(${DB_EXISTS(CFIM/302)}?dialfw:dial)
exten => 302,n(dialfw),Set(extension=${DB(CFIM/302)})
exten => 302,n,Set(wait=${MATH(${DB(NumRing/302)}*6,int)})
exten => 302,n,ExecIf($["${wait}" !=
"0"]|Dial|SIP/XXXXXX2|${wait}|g|)
exten => 302,n,Dial(DAHDI/g1/${extension},90,g)
exten => 302,n,Macro(handle-hangup)
exten => 302,n(dial),Dial(SIP/XXXXXX2,30,g)
exten => 302,n,Voicemail(302,u)
exten => 302,n,Macro(handle-hangup)

exten => 303,1,GotoIf(${DB_EXISTS(CFIM/303)}?dialfw:dial)
exten => 303,n(dialfw),Set(extension=${DB(CFIM/303)})
exten => 303,n,Set(wait=${MATH(${DB(NumRing/303)}*6,int)})
exten => 303,n,ExecIf($["${wait}" !=
"0"]|Dial|SIP/XXXXXX3|${wait}|g|)
exten => 303,n,Dial(DAHDI/g1/${extension},90,g)
exten => 303,n,Macro(handle-hangup)
exten => 303,n(dial),Dial(SIP/XXXXXX3,30,g)
exten => 303,n,Voicemail(303,u)
exten => 303,n,Macro(handle-hangup)

exten => 0,1,Answer
exten => 0,n,SIPAddHeader(Alert-Info: info=<Bellcore-dr4>)
exten =>
0,n,Dial(SIP/XXXXXX2&SIP/XXXXXX3&SIP/XXXXXX4&SIP/XXXXXX5&SIP/XXXXXX6&SIP/XXXXXX7,25,g)
exten => 0,n,Voicemail(300,u)
exten => 0,n,Macro(handle-hangup)

exten => t,1,Answer
exten => t,n,SIPAddHeader(Alert-Info: info=<Bellcore-dr4>)
exten =>
t,n,Dial(SIP/XXXXXX2&SIP/XXXXXX3&SIP/XXXXXX4&SIP/XXXXXX5&SIP/XXXXXX6&SIP/XXXXXX7,25,g)
exten => t,n,Voicemail(300,u)
exten => t,n,Macro(handle-hangup)

exten => i,1,Playback(XXXXXX/invalid)
exten => i,n,Goto(s,1)

And this is the outgoing dialplan for the customer (for internal lines and
special features)

[XXXXXX]

exten => _*98,1,Answer
exten => _*98,n,VoicemailMain()

exten => _*88,1,Answer
exten => _*88,n,VoicemailMain(300)

exten => _*72,1,Answer
exten => _*72,n,Wait(1)
exten => _*72,n,Read(extension,XXXXXX/enter-extension,3)
exten => _*72,n,Read(fwdnum,XXXXXX/forward-to,10)
exten => _*72,n,Read(numrings,XXXXXX/num-of-rings,1)
exten => _*72,n,Set(DB(CFIM/${extension})="${fwdnum}")
exten => _*72,n,NoOp(Numrings: "${numrings}" ${numrings})
exten => _*72,n,Set(DB(NumRing/${extension})="${numrings}")
exten => _*72,n,Playback(XXXXXX/your-extension)
exten => _*72,n,SayDigits(${extension})
exten => _*72,n,Playback(XXXXXX/will-forward-to)
exten => _*72,n,SayDigits(${fwdnum})
exten => _*72,n,Playback(XXXXXX/after)
exten => _*72,n,SayDigits(${numrings})
exten => _*72,n,Playback(XXXXXX/rings)
exten => _*72,n,Macro(handle-hangup)

exten => _*73,1,Answer
exten => _*73,n,Wait(1)
exten => _*73,n,Read(extension,XXXXXX/enter-extension,3)
exten => _*73,n,Set(${DB_DELETE(CFIM/${extension}))
exten => _*73,n,Playback(XXXXXX/cfwd-cancelled)
exten => _*73,n,Macro(handle-hangup)

exten => 302,1,Set(CALLERID(name)="Internal call")
exten => 302,n,GotoIf(${DB_EXISTS(CFIM/302)}?dialfw:dial)
exten => 302,n(dialfw),Set(extension=${DB(CFIM/302)})
exten => 302,n,Set(wait=${MATH(${DB(NumRing/302)}*6,int)})
exten => 302,n,ExecIf($["${wait}" !=
"0"]|Dial,SIP/XXXXXX2,${wait},g)
exten => 302,n,Dial(DAHDI/g1/${extension},90,g)
exten => 302,n,Macro(handle-hangup)
exten => 302,n(dial),Dial(SIP/XXXXXX2,20,g)
exten => 302,n,Voicemail(302,u)
exten => 302,n,Macro(handle-hangup)

exten => 303,1,Set(CALLERID(name)="Internal call")
exten => 303,n,GotoIf(${DB_EXISTS(CFIM/303)}?dialfw:dial)
exten => 303,n(dialfw),Set(extension=${DB(CFIM/303)})
exten => 303,n,Set(wait=${MATH(${DB(NumRing/303)}*6,int)})
exten => 303,n,ExecIf($["${wait}" !=
"0"]|Dial,SIP/XXXXXX3,${wait},g)
exten => 303,n,Dial(DAHDI/g1/${extension},90,g)
exten => 303,n,Macro(handle-hangup)
exten => 303,n(dial),Dial(SIP/XXXXXX3,20,g)
exten => 303,n,Voicemail(303,u)
exten => 303,n,Macro(handle-hangup)

include => vancouver