Direct Dial Virtual Extension with Follow-Me from IVR not working

This is my first post to the forum, so I hope someone can please help out.

I’m the phone vendor for the a client we’ve just installed a FreePBX distro. And basically everything had run pretty smoothly, until this.

They are using the iSymphony Operator Panel, licensed for 15 users, 4 queues. And they wanted to add virtual extensions for customer to be able to dial and extension that rings to their cell phones.

So by reading some other topics in the forum, I decided to go the route of setting them up with Virtual Extensions with Follow Me.

In the FollowMe I used the Following setting

Extension: 901
Ring Stategy: RingAll
Ring Time: 30
Follow-Me List: NXXNXXNXXX# (This is the format I used)

Now internall, if I dial the extensions from another extension, it will ring through to the outside line using the outbound trunk as desired.

However, if calling the main DID, which eventually leads to an IVR with Direct Dial enabled. I try and dial 901 and it rings once, and replays the IVR message again.

So my question is, why is it doing this? It’s an extension, it should work right? I can get through to other SIP/Extensions just fine using direct dial.

It’s not an extension though! You’ll need to add an entry for each ring group to the IVR.

Instead of a virtual extension w/ Follow Me, try using a custom extension. In the custom technology field use this format:
local/1234567890@outbound-allroutes

Where the digits represent your cell phone number(s)

lgaetz, thank you for the alternative solution. I haven’t tried this yet, but just by looking at the string you suggested I have a question.

Is “outbound-allroutes” an asterisk alias for “all outbound routes” or something? I’ve never used custom extensions before. And I’m not an “asterisk” expert yet, still learning.

By looking at that string I would think it needs to be the specific name of the outbound route to use?

Forgive my ignorance, I’m still learning the nuances of asterisk. But I thought the purpose of creating a virtual extension would be to “immitate” an actual SIP/IAX/Custom extension, thereby inheriting the operation and properties of a “real” extension? I’ve not created any ring groups, the virtual extensions show up in iSymphony just like the sip extensions do, and are able to be dialed internally.

I guess my question would be why is it not treated the same way from the IVR as it would be internally?

The first nuance you should learn as an “ITGuy” is that FreePBX is a front end to Asterisk and not Asterisk itself. The WIKI here will I am sure save you a lot more posts if you actually read it through.

Thank you dicko, I realize that. And I’ve worked with asterisk before using different “front ends” like vicibox when I worked for a call center. And and I am familiar working with the CLI to some extent. The point of my original question was, I am very knowledgeable in linux, I’m comfortable writing perl scripts, my question more or less was about the topology of extensions, and why the virtual extension would be recognized differently than a “real” extension such as a SIP or IAX or Custom Extension. And we’re not in an “Asterisk” forum, this is “FreePBX” forum. So please if your replies are only to belittle those who are asking for help because they do not understand the intricacies of the command line asterisk, and every little parameter in a config file, then please keep your comments to yourself. I do not have to explain my experience or my abilities to you, if you cannot be part of the thread in a productive manner than find yourself another thread to belittle. Bye Bye.

I misread your post, for some reason I thought you said you had set up a ring group, not a follow-me from a virtual extension. That should definitely be working fine if “Direct Dial” is set to “Extensions”.

outbound-allroutes is an Asterisk dialplan context created by FreePBX that contains all the outbound routes you’ve set up. From Asterisk CLI try [font=Courier]dialplan show outbound-allroutes[/font] to see the dialplan or [font=Courier]dialplan show 12345678901@outbound-allroutes[/font] to see how it’s applied to a specific number.

That’s exactly why I am baffled, if I dial from an internal SIP extension, to the Virtual Extension, with a follow me of an out side 10digit line NXXNXXNXXX# in that format, it works. But if I try typing in that extensions when the IVR answers through the main Inbound route. It rings once, and say unable to complete this call. Or something like that.

Now I went ahead an tried setting them all up as local/#@outbound-allroutes to see if it would work that way, but it’s pretty much the same problem, instead it gives a busy tone instead of the message.

So I’m stumped. I told the customer that they would be able to do this, because it worked internally, and I don’t know if this is important though, but all of the external extensions they wanted set up were all in this format “9XX” extensions. I don’t think that really matters though, and yes the IVR has “extensions” as it’s Direct Dial method. And I do not have and CID restrictions on the Outbound routes that would restrict it.

Any thought’s or ideas??

It works fine for our 2.10 system. Maybe try putting an entry for each one in the IVR?

Or post some call logs.

Ok, set an extension back up as virtual exten 801, with follow me to the outbound 67887389XX number. The outside caller is me calling from my cell phone as CID 72727241XX (CLEARWATER, FL) number, I replace the last two digits for privacy reasons in the call log. 4046999999 is the main inbound DID for the biz that goes to the time conditions and then to sales I have setup. If you want to call that.

Now what’s doing is it rings once in the IVR after typing extension 801, which has a follow me with the 67887389XX to dial, dialplan is ring all, dialtime is 30 seconds. Initial ring is set to 0 in follow me to bypass since it’s a virtual extension, I want it to go right into the Follow Me.

Here is the asterisk log details from what I could gather, this is an active call center so it’s kind of hard to pinpoint my exact call stack mixed in with theirs. Maybe someone can see something I am missing, it says that the channel is busy. I’ve tried dialing that number from the system and it does not give a busy signal. So I don’t know what the hell is going on with it. By all accounts it should be working…

[2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [40469999XX@from-trunk:1] Set("SIP/40469999XX-0000051f", "__FROM_DID=40469999XX") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [40469999XX@from-trunk:2] Gosub("SIP/40469999XX-0000051f", "app-blacklist-check,s,1()") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [s@app-blacklist-check:1] GotoIf("SIP/40469999XX-0000051f", "0?blacklisted") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [s@app-blacklist-check:2] Set("SIP/40469999XX-0000051f", "CALLED_BLACKLIST=1") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [s@app-blacklist-check:3] Return("SIP/40469999XX-0000051f", "") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [40469999XX@from-trunk:3] Set("SIP/40469999XX-0000051f", "CDR(did)=40469999XX") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [40469999XX@from-trunk:4] ExecIf("SIP/40469999XX-0000051f", "0 ?Set(CALLERID(name)=72727241XX)") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [40469999XX@from-trunk:5] Set("SIP/40469999XX-0000051f", "__CALLINGPRES_SV=allowed_not_screened") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [40469999XX@from-trunk:6] Set("SIP/40469999XX-0000051f", "CALLERPRES()=allowed_not_screened") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [40469999XX@from-trunk:7] Goto("SIP/40469999XX-0000051f", "timeconditions,9,1") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Goto (timeconditions,9,1) [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [9@timeconditions:1] GotoIfTime("SIP/40469999XX-0000051f", "*,*,4,jul?truestate") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [9@timeconditions:2] GotoIfTime("SIP/40469999XX-0000051f", "*,*,2,sep?truestate") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [9@timeconditions:3] GotoIfTime("SIP/40469999XX-0000051f", "*,*,27,may?truestate") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [9@timeconditions:4] GotoIf("SIP/40469999XX-0000051f", "0?truegoto") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [9@timeconditions:5] ExecIf("SIP/40469999XX-0000051f", "0?Set(DB(TC/9)=)") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [9@timeconditions:6] GotoIf("SIP/40469999XX-0000051f", "1?timeconditions,1,1") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Goto (timeconditions,1,1) [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [1@timeconditions:1] GotoIfTime("SIP/40469999XX-0000051f", "08:00-11:59,mon-fri,*,*?truestate") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Goto (timeconditions,1,8) [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [1@timeconditions:8] GotoIf("SIP/40469999XX-0000051f", "0?falsegoto") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [1@timeconditions:9] ExecIf("SIP/40469999XX-0000051f", "0?Set(DB(TC/1)=)") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [1@timeconditions:10] GotoIf("SIP/40469999XX-0000051f", "1?timeconditions,10,1") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Goto (timeconditions,10,1) [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [10@timeconditions:1] GotoIfTime("SIP/40469999XX-0000051f", "08:00-11:59,mon-fri,*,*?truestate") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Goto (timeconditions,10,8) [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [10@timeconditions:8] GotoIf("SIP/40469999XX-0000051f", "0?falsegoto") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [10@timeconditions:9] ExecIf("SIP/40469999XX-0000051f", "0?Set(DB(TC/10)=)") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [10@timeconditions:10] GotoIf("SIP/40469999XX-0000051f", "1?ivr-1,s,1") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Goto (ivr-1,s,1) [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [s@ivr-1:1] Set("SIP/40469999XX-0000051f", "TIMEOUT_LOOPCOUNT=0") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [s@ivr-1:2] Set("SIP/40469999XX-0000051f", "_IVR_CONTEXT_ivr-1=") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [s@ivr-1:3] Set("SIP/40469999XX-0000051f", "_IVR_CONTEXT=ivr-1") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [s@ivr-1:4] Set("SIP/40469999XX-0000051f", "__IVR_RETVM=RETURN") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [s@ivr-1:5] GotoIf("SIP/40469999XX-0000051f", "0?skip") in new stack [2013-05-28 10:15:54] VERBOSE[22079] pbx.c: -- Executing [s@ivr-1:6] Answer("SIP/40469999XX-0000051f", "") in new stack [2013-05-28 10:15:55] VERBOSE[22079] pbx.c: -- Executing [s@ivr-1:7] Wait("SIP/40469999XX-0000051f", "1") in new stack [2013-05-28 10:15:55] VERBOSE[22062] pbx.c: -- Executing [s@ivr-1:11] WaitExten("SIP/40469999XX-0000051b", "4,") in new stack [2013-05-28 10:15:56] VERBOSE[22079] pbx.c: -- Executing [s@ivr-1:8] Set("SIP/40469999XX-0000051f", "IVR_MSG=custom/DayModeAA") in new stack [2013-05-28 10:15:56] VERBOSE[22079] pbx.c: -- Executing [s@ivr-1:9] Set("SIP/40469999XX-0000051f", "TIMEOUT(digit)=3") in new stack [2013-05-28 10:15:56] VERBOSE[22079] func_timeout.c: -- Digit timeout set to 3.000 [2013-05-28 10:15:56] VERBOSE[22079] pbx.c: -- Executing [s@ivr-1:10] ExecIf("SIP/40469999XX-0000051f", "1?Background(custom/DayModeAA)") in new stack [2013-05-28 10:15:56] VERBOSE[22079] file.c: -- Playing 'custom/DayModeAA.gsm' (language 'en') [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: == CDR updated on SIP/40469999XX-0000051f [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@ivr-1:1] Macro("SIP/40469999XX-0000051f", "blkvm-clr,") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-blkvm-clr:1] Set("SIP/40469999XX-0000051f", "SHARED(BLKVM,)=") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-blkvm-clr:2] Set("SIP/40469999XX-0000051f", "GOSUB_RETVAL=") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-blkvm-clr:3] MacroExit("SIP/40469999XX-0000051f", "") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@ivr-1:2] Set("SIP/40469999XX-0000051f", "__NODEST=") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@ivr-1:3] Goto("SIP/40469999XX-0000051f", "from-did-direct,801,1") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Goto (from-did-direct,801,1) [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:1] GotoIf("SIP/40469999XX-0000051f", "0?ext-local,801,1") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:2] Macro("SIP/40469999XX-0000051f", "user-callerid,") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:1] Set("SIP/40469999XX-0000051f", "AMPUSER=72727241XX") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/40469999XX-0000051f", "0?report") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/40469999XX-0000051f", "1?Set(REALCALLERIDNUM=72727241XX)") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:4] Set("SIP/40469999XX-0000051f", "AMPUSER=") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:5] Set("SIP/40469999XX-0000051f", "AMPUSERCIDNAME=") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/40469999XX-0000051f", "1?report") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Goto (macro-user-callerid,s,13) [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:13] GotoIf("SIP/40469999XX-0000051f", "0?continue") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:14] Set("SIP/40469999XX-0000051f", "__TTL=64") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:15] GotoIf("SIP/40469999XX-0000051f", "1?continue") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Goto (macro-user-callerid,s,26) [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:26] Set("SIP/40469999XX-0000051f", "CALLERID(number)=72727241XX") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:27] Set("SIP/40469999XX-0000051f", "CALLERID(name)=CLEARWATER FL") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:28] Set("SIP/40469999XX-0000051f", "CHANNEL(language)=en") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:3] Set("SIP/40469999XX-0000051f", "DIAL_OPTIONS=trI") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:4] Set("SIP/40469999XX-0000051f", "CONNECTEDLINE(num)=801") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:5] Set("SIP/40469999XX-0000051f", "CONNECTEDLINE(name,i)=XAVIER MONTS") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:6] Set("SIP/40469999XX-0000051f", "FM_DIALSTATUS=UNKNOWN") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:7] Set("SIP/40469999XX-0000051f", "__EXTTOCALL=801") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:8] Set("SIP/40469999XX-0000051f", "__PICKUPMARK=801") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:9] Macro("SIP/40469999XX-0000051f", "blkvm-setifempty,") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-blkvm-setifempty:1] GotoIf("SIP/40469999XX-0000051f", "1?init") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Goto (macro-blkvm-setifempty,s,4) [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-blkvm-setifempty:4] Set("SIP/40469999XX-0000051f", "__BLKVM_CHANNEL=SIP/40469999XX-0000051f") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-blkvm-setifempty:5] Set("SIP/40469999XX-0000051f", "SHARED(BLKVM,SIP/40469999XX-0000051f)=TRUE") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-blkvm-setifempty:6] Set("SIP/40469999XX-0000051f", "GOSUB_RETVAL=TRUE") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-blkvm-setifempty:7] MacroExit("SIP/40469999XX-0000051f", "") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:10] GotoIf("SIP/40469999XX-0000051f", "1?skipov") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Goto (from-did-direct,801,13) [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:13] Set("SIP/40469999XX-0000051f", "RRNODEST=") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:14] Set("SIP/40469999XX-0000051f", "__NODEST=801") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:15] GosubIf("SIP/40469999XX-0000051f", "0?sub-fmsetcid,s,1()") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:16] Set("SIP/40469999XX-0000051f", "RecordMethod=Group") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:17] Gosub("SIP/40469999XX-0000051f", "sub-record-check,s,1(exten,801,)") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:1] GotoIf("SIP/40469999XX-0000051f", "1?check") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Goto (sub-record-check,s,6) [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:6] Set("SIP/40469999XX-0000051f", "__MON_FMT=wav") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:7] GotoIf("SIP/40469999XX-0000051f", "1?next") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Goto (sub-record-check,s,10) [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:10] ExecIf("SIP/40469999XX-0000051f", "0?Return()") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:11] GotoIf("SIP/40469999XX-0000051f", "0?exten,1") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:12] Set("SIP/40469999XX-0000051f", "__REC_STATUS=INITIALIZED") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:13] ExecIf("SIP/40469999XX-0000051f", "0?Set(__REC_POLICY_MODE=)") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:14] Set("SIP/40469999XX-0000051f", "NOW=1369750558") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:15] Set("SIP/40469999XX-0000051f", "__DAY=28") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:16] Set("SIP/40469999XX-0000051f", "__MONTH=05") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:17] Set("SIP/40469999XX-0000051f", "__YEAR=2013") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:18] Set("SIP/40469999XX-0000051f", "__TIMESTR=20130528-101558") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:19] Set("SIP/40469999XX-0000051f", "__FROMEXTEN=72727241XX") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:20] Set("SIP/40469999XX-0000051f", "__CALLFILENAME=exten-801-72727241XX-20130528-101558-1369750554.29052") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@sub-record-check:21] Goto("SIP/40469999XX-0000051f", "exten,1") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Goto (sub-record-check,exten,1) [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [exten@sub-record-check:1] GotoIf("SIP/40469999XX-0000051f", "0?callee") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [exten@sub-record-check:2] Set("SIP/40469999XX-0000051f", "__REC_POLICY_MODE=dontcare") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [exten@sub-record-check:3] GotoIf("SIP/40469999XX-0000051f", "1?caller") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Goto (sub-record-check,exten,10) [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [exten@sub-record-check:10] Set("SIP/40469999XX-0000051f", "__REC_POLICY_MODE=") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [exten@sub-record-check:11] GosubIf("SIP/40469999XX-0000051f", "0?record,1(exten,801,72727241XX)") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [exten@sub-record-check:12] Return("SIP/40469999XX-0000051f", "") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:18] GotoIf("SIP/40469999XX-0000051f", "1 ?skipsimple") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Goto (from-did-direct,801,20) [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:20] Set("SIP/40469999XX-0000051f", "RingGroupMethod=ringall") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:21] Set("SIP/40469999XX-0000051f", "_FMGRP=801") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:22] GotoIf("SIP/40469999XX-0000051f", "0?doconfirm") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:23] Macro("SIP/40469999XX-0000051f", "dial,20,trI,801-67887389XX#") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-dial:1] GotoIf("SIP/40469999XX-0000051f", "1?dial") in new stack [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Goto (macro-dial,s,3) [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-dial:3] AGI("SIP/40469999XX-0000051f", "dialparties.agi") in new stack [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: dialparties.agi: Starting New Dialparties.agi [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: dialparties.agi: Caller ID name is 'CLEARWATER FL' number is '72727241XX' [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: dialparties.agi: Methodology of ring is 'ringall' [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: -- dialparties.agi: Added extension 801 to extension map [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: -- dialparties.agi: Added extension 67887389XX# to extension map [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: -- dialparties.agi: Extension 801 cf is disabled [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: -- dialparties.agi: Extension 67887389XX# cf is disabled [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: -- dialparties.agi: Extension 801 do not disturb is disabled [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: dialparties.agi: EXTENSION_STATE: 4 (UNKNOWN) [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: dialparties.agi: Extension 801 has ExtensionState: 4 [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: -- dialparties.agi: Checking CW and CFB status for extension 801 [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: -- dialparties.agi: dbset CALLTRACE/801 to 72727241XX [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: -- dialparties.agi: Filtered ARG3: 801-67887389XX [2013-05-28 10:15:58] VERBOSE[22079] res_agi.c: -- AGI Script dialparties.agi completed, returning 0 [2013-05-28 10:15:58] VERBOSE[22079] pbx.c: -- Executing [s@macro-dial:7] Dial("SIP/40469999XX-0000051f", "Local/67887389XX@from-internal/n,20,trIM(auto-blkvm)") in new stack [2013-05-28 10:15:58] VERBOSE[22079] app_dial.c: -- Called Local/67887389XX@from-internal/n [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [67887389XX@from-internal:1] Macro("Local/67887389XX@from-internal-0000362c;2", "user-callerid,LIMIT,") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-user-callerid:1] Set("Local/67887389XX@from-internal-0000362c;2", "AMPUSER=72727241XX") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-user-callerid:2] GotoIf("Local/67887389XX@from-internal-0000362c;2", "0?report") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-user-callerid:3] ExecIf("Local/67887389XX@from-internal-0000362c;2", "1?Set(REALCALLERIDNUM=72727241XX)") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-user-callerid:4] Set("Local/67887389XX@from-internal-0000362c;2", "AMPUSER=") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-user-callerid:5] Set("Local/67887389XX@from-internal-0000362c;2", "AMPUSERCIDNAME=") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("Local/67887389XX@from-internal-0000362c;2", "1?report") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Goto (macro-user-callerid,s,13) [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-user-callerid:13] GotoIf("Local/67887389XX@from-internal-0000362c;2", "1?continue") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Goto (macro-user-callerid,s,26) [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-user-callerid:26] Set("Local/67887389XX@from-internal-0000362c;2", "CALLERID(number)=72727241XX") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-user-callerid:27] Set("Local/67887389XX@from-internal-0000362c;2", "CALLERID(name)=CLEARWATER FL") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-user-callerid:28] Set("Local/67887389XX@from-internal-0000362c;2", "CHANNEL(language)=en") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [67887389XX@from-internal:2] Set("Local/67887389XX@from-internal-0000362c;2", "MOHCLASS=Line-In") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [67887389XX@from-internal:3] ExecIf("Local/67887389XX@from-internal-0000362c;2", "0?Set(TRUNKCIDOVERRIDE=40469999XX)") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [67887389XX@from-internal:4] Set("Local/67887389XX@from-internal-0000362c;2", "_NODEST=") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [67887389XX@from-internal:5] Gosub("Local/67887389XX@from-internal-0000362c;2", "sub-record-check,s,1(out,67887389XX,)") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@sub-record-check:1] GotoIf("Local/67887389XX@from-internal-0000362c;2", "1?check") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Goto (sub-record-check,s,6) [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@sub-record-check:6] Set("Local/67887389XX@from-internal-0000362c;2", "__MON_FMT=wav") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@sub-record-check:7] GotoIf("Local/67887389XX@from-internal-0000362c;2", "1?next") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Goto (sub-record-check,s,10) [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@sub-record-check:10] ExecIf("Local/67887389XX@from-internal-0000362c;2", "0?Return()") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@sub-record-check:11] GotoIf("Local/67887389XX@from-internal-0000362c;2", "1?out,1") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Goto (sub-record-check,out,1) [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [out@sub-record-check:1] ExecIf("Local/67887389XX@from-internal-0000362c;2", "1?Set(__REC_POLICY_MODE=)") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [out@sub-record-check:2] GosubIf("Local/67887389XX@from-internal-0000362c;2", "0?record,1(exten,67887389XX,72727241XX)") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [out@sub-record-check:3] Return("Local/67887389XX@from-internal-0000362c;2", "") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [67887389XX@from-internal:6] Macro("Local/67887389XX@from-internal-0000362c;2", "dialout-trunk,4,67887389XX,") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:1] Set("Local/67887389XX@from-internal-0000362c;2", "DIAL_TRUNK=4") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:2] GosubIf("Local/67887389XX@from-internal-0000362c;2", "0?sub-pincheck,s,1()") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:3] GotoIf("Local/67887389XX@from-internal-0000362c;2", "0?disabletrunk,1") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:4] Set("Local/67887389XX@from-internal-0000362c;2", "DIAL_NUMBER=67887389XX") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:5] Set("Local/67887389XX@from-internal-0000362c;2", "DIAL_TRUNK_OPTIONS=tr") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:6] Set("Local/67887389XX@from-internal-0000362c;2", "OUTBOUND_GROUP=OUT_4") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:7] GotoIf("Local/67887389XX@from-internal-0000362c;2", "0?nomax") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:8] GotoIf("Local/67887389XX@from-internal-0000362c;2", "0?chanfull") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:9] GotoIf("Local/67887389XX@from-internal-0000362c;2", "0?skipoutcid") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:10] Set("Local/67887389XX@from-internal-0000362c;2", "DIAL_TRUNK_OPTIONS=") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:11] Macro("Local/67887389XX@from-internal-0000362c;2", "outbound-callerid,4") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outbound-callerid:1] ExecIf("Local/67887389XX@from-internal-0000362c;2", "1?Set(CALLERPRES()=allowed_not_screened)") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outbound-callerid:2] ExecIf("Local/67887389XX@from-internal-0000362c;2", "0?Set(REALCALLERIDNUM=72727241XX)") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outbound-callerid:3] GotoIf("Local/67887389XX@from-internal-0000362c;2", "0?normcid") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outbound-callerid:4] Set("Local/67887389XX@from-internal-0000362c;2", "USEROUTCID=72727241XX") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outbound-callerid:5] GotoIf("Local/67887389XX@from-internal-0000362c;2", "1?bypass") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Goto (macro-outbound-callerid,s,7) [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outbound-callerid:7] Set("Local/67887389XX@from-internal-0000362c;2", "EMERGENCYCID=") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outbound-callerid:8] Set("Local/67887389XX@from-internal-0000362c;2", "TRUNKOUTCID=40469999XX") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outbound-callerid:9] GotoIf("Local/67887389XX@from-internal-0000362c;2", "1?trunkcid") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Goto (macro-outbound-callerid,s,12) [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outbound-callerid:12] ExecIf("Local/67887389XX@from-internal-0000362c;2", "1?Set(CALLERID(all)=40469999XX)") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outbound-callerid:13] ExecIf("Local/67887389XX@from-internal-0000362c;2", "1?Set(CALLERID(all)=72727241XX)") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outbound-callerid:14] ExecIf("Local/67887389XX@from-internal-0000362c;2", "0?Set(CALLERID(all)=)") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outbound-callerid:15] ExecIf("Local/67887389XX@from-internal-0000362c;2", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:12] GosubIf("Local/67887389XX@from-internal-0000362c;2", "0?sub-flp-4,s,1()") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:13] Set("Local/67887389XX@from-internal-0000362c;2", "OUTNUM=67887389XX") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:14] Set("Local/67887389XX@from-internal-0000362c;2", "custom=SIP/cbeyond") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:15] ExecIf("Local/67887389XX@from-internal-0000362c;2", "1?Set(DIAL_TRUNK_OPTIONS=M(setmusic^Line-In))") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:16] ExecIf("Local/67887389XX@from-internal-0000362c;2", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^Line-In)M(confirm))") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:17] Macro("Local/67887389XX@from-internal-0000362c;2", "dialout-trunk-predial-hook,") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("Local/67887389XX@from-internal-0000362c;2", "") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:18] GotoIf("Local/67887389XX@from-internal-0000362c;2", "0?bypass,1") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:19] ExecIf("Local/67887389XX@from-internal-0000362c;2", "0?Set(CONNECTEDLINE(num,i)=67887389XX)") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:20] ExecIf("Local/67887389XX@from-internal-0000362c;2", "0?Set(CONNECTEDLINE(name,i)=CID:72727241XX)") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:21] GotoIf("Local/67887389XX@from-internal-0000362c;2", "0?customtrunk") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:22] Dial("Local/67887389XX@from-internal-0000362c;2", "SIP/cbeyond/67887389XX,300,M(setmusic^Line-In)") in new stack [2013-05-28 10:15:58] VERBOSE[22081] netsock2.c: == Using SIP RTP TOS bits 184 [2013-05-28 10:15:58] VERBOSE[22081] netsock2.c: == Using SIP RTP CoS mark 5 [2013-05-28 10:15:58] VERBOSE[22081] app_dial.c: -- Called SIP/cbeyond/67887389XX [2013-05-28 10:15:58] VERBOSE[22081] app_dial.c: == Everyone is busy/congested at this time (1:0/0/1) [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:23] NoOp("Local/67887389XX@from-internal-0000362c;2", "Dial failed for some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 1") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-dialout-trunk:24] Goto("Local/67887389XX@from-internal-0000362c;2", "s-CHANUNAVAIL,1") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Goto (macro-dialout-trunk,s-CHANUNAVAIL,1) [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s-CHANUNAVAIL@macro-dialout-trunk:1] Set("Local/67887389XX@from-internal-0000362c;2", "RC=1") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s-CHANUNAVAIL@macro-dialout-trunk:2] Goto("Local/67887389XX@from-internal-0000362c;2", "1,1") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Goto (macro-dialout-trunk,1,1) [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [1@macro-dialout-trunk:1] Goto("Local/67887389XX@from-internal-0000362c;2", "continue,1") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Goto (macro-dialout-trunk,continue,1) [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [continue@macro-dialout-trunk:1] GotoIf("Local/67887389XX@from-internal-0000362c;2", "1?noreport") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Goto (macro-dialout-trunk,continue,3) [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [continue@macro-dialout-trunk:3] NoOp("Local/67887389XX@from-internal-0000362c;2", "TRUNK Dial failed due to CHANUNAVAIL HANGUPCAUSE: 1 - failing through to other trunks") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [continue@macro-dialout-trunk:4] Set("Local/67887389XX@from-internal-0000362c;2", "CALLERID(number)=") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [67887389XX@from-internal:7] Macro("Local/67887389XX@from-internal-0000362c;2", "outisbusy,") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outisbusy:1] Progress("Local/67887389XX@from-internal-0000362c;2", "") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outisbusy:2] GotoIf("Local/67887389XX@from-internal-0000362c;2", "0?emergency,1") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outisbusy:3] GotoIf("Local/67887389XX@from-internal-0000362c;2", "0?intracompany,1") in new stack [2013-05-28 10:15:58] VERBOSE[22081] pbx.c: -- Executing [s@macro-outisbusy:4] Playback("Local/67887389XX@from-internal-0000362c;2", "all-circuits-busy-now&pls-try-call-later, noanswer") in new stack [2013-05-28 10:15:58] VERBOSE[22081] file.c: -- Playing 'all-circuits-busy-now.ulaw' (language 'en') [2013-05-28 10:15:58] VERBOSE[22079] app_dial.c: -- Local/67887389XX@from-internal-0000362c;1 is making progress passing it to SIP/40469999XX-0000051f [2013-05-28 10:15:59] VERBOSE[22069] app_dial.c: -- SIP/102-0000051e answered Local/102@from-queue-0000362b;2 [2013-05-28 10:15:59] VERBOSE[22069] pbx.c: -- Executing [s@macro-auto-blkvm:1] Set("SIP/102-0000051e", "__MACRO_RESULT=") in new stack [2013-05-28 10:15:59] VERBOSE[22069] pbx.c: -- Executing [s@macro-auto-blkvm:2] Macro("SIP/102-0000051e", "blkvm-clr,") in new stack [2013-05-28 10:15:59] VERBOSE[22069] pbx.c: -- Executing [s@macro-blkvm-clr:1] Set("SIP/102-0000051e", "SHARED(BLKVM,SIP/40469999XX-00000517)=") in new stack [2013-05-28 10:15:59] VERBOSE[22069] pbx.c: -- Executing [s@macro-blkvm-clr:2] Set("SIP/102-0000051e", "GOSUB_RETVAL=") in new stack [2013-05-28 10:15:59] VERBOSE[22069] pbx.c: -- Executing [s@macro-blkvm-clr:3] MacroExit("SIP/102-0000051e", "") in new stack [2013-05-28 10:15:59] VERBOSE[22069] pbx.c: -- Executing [s@macro-auto-blkvm:3] ExecIf("SIP/102-0000051e", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=102)") in new stack [2013-05-28 10:15:59] VERBOSE[22069] pbx.c: -- Executing [s@macro-auto-blkvm:4] ExecIf("SIP/102-0000051e", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=Keith Allison)") in new stack [2013-05-28 10:15:59] VERBOSE[22042] app_queue.c: -- Local/102@from-queue-0000362b;1 answered SIP/40469999XX-00000517 [2013-05-28 10:15:59] VERBOSE[22042] file.c: -- Playing 'queue-reporthold.ulaw' (language 'en') [2013-05-28 10:15:59] VERBOSE[22062] pbx.c: -- Timeout on SIP/40469999XX-0000051b, going to 't' [2013-05-28 10:15:59] VERBOSE[22062] pbx.c: -- Executing [t@ivr-1:1] Set("SIP/40469999XX-0000051b", "TIMEOUT_LOOPCOUNT=1") in new stack [2013-05-28 10:15:59] VERBOSE[22062] pbx.c: -- Executing [t@ivr-1:2] GotoIf("SIP/40469999XX-0000051b", "0?final") in new stack [2013-05-28 10:15:59] VERBOSE[22062] pbx.c: -- Executing [t@ivr-1:3] Set("SIP/40469999XX-0000051b", "IVR_MSG=custom/DayModeAA") in new stack [2013-05-28 10:15:59] VERBOSE[22062] pbx.c: -- Executing [t@ivr-1:4] Goto("SIP/40469999XX-0000051b", "s,start") in new stack [2013-05-28 10:15:59] VERBOSE[22062] pbx.c: -- Goto (ivr-1,s,9) [2013-05-28 10:15:59] VERBOSE[22062] pbx.c: -- Executing [s@ivr-1:9] Set("SIP/40469999XX-0000051b", "TIMEOUT(digit)=3") in new stack [2013-05-28 10:15:59] VERBOSE[22062] func_timeout.c: -- Digit timeout set to 3.000 [2013-05-28 10:15:59] VERBOSE[22062] pbx.c: -- Executing [s@ivr-1:10] ExecIf("SIP/40469999XX-0000051b", "1?Background(custom/DayModeAA)") in new stack [2013-05-28 10:15:59] VERBOSE[22062] file.c: -- Playing 'custom/DayModeAA.gsm' (language 'en') [2013-05-28 10:16:00] VERBOSE[22042] file.c: -- Playing 'digits/11.ulaw' (language 'en') [2013-05-28 10:16:00] VERBOSE[22081] file.c: -- Playing 'pls-try-call-later.ulaw' (language 'en') [2013-05-28 10:16:00] VERBOSE[22082] pbx_spool.c: -- Attempting call on Local/s@tc-maint for application NoCDR() (Retry 1) [2013-05-28 10:16:00] VERBOSE[22083] pbx.c: -- Executing [s@tc-maint:1] NoCDR("Local/s@tc-maint-0000362d;2", "") in new stack [2013-05-28 10:16:00] VERBOSE[22083] pbx.c: -- Executing [s@tc-maint:2] Set("Local/s@tc-maint-0000362d;2", "TCMAINT=RETURN") in new stack [2013-05-28 10:16:00] VERBOSE[22083] pbx.c: -- Executing [s@tc-maint:3] GosubIf("Local/s@tc-maint-0000362d;2", "0?timeconditions,10,1()") in new stack [2013-05-28 10:16:00] VERBOSE[22083] pbx.c: -- Executing [s@tc-maint:4] System("Local/s@tc-maint-0000362d;2", "/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 0") in new stack [2013-05-28 10:16:00] VERBOSE[22083] pbx.c: -- Executing [s@tc-maint:5] Answer("Local/s@tc-maint-0000362d;2", "") in new stack [2013-05-28 10:16:00] NOTICE[22082] pbx_spool.c: Call completed to Local/s@tc-maint [2013-05-28 10:16:00] VERBOSE[22083] pbx.c: == Spawn extension (tc-maint, s, 5) exited non-zero on 'Local/s@tc-maint-0000362d;2' [2013-05-28 10:16:01] VERBOSE[22042] file.c: -- Playing 'queue-seconds.ulaw' (language 'en') [2013-05-28 10:16:01] VERBOSE[22042] res_musiconhold.c: -- Stopped music on hold on SIP/40469999XX-00000517 [2013-05-28 10:16:01] VERBOSE[22085] app_mixmonitor.c: == Begin MixMonitor Recording SIP/40469999XX-00000517 [2013-05-28 10:16:02] VERBOSE[22081] pbx.c: -- Executing [s@macro-outisbusy:5] Congestion("Local/67887389XX@from-internal-0000362c;2", "20") in new stack [2013-05-28 10:16:02] VERBOSE[22079] app_dial.c: -- Local/67887389XX@from-internal-0000362c;1 is circuit-busy [2013-05-28 10:16:02] VERBOSE[22081] app_macro.c: == Spawn extension (macro-outisbusy, s, 5) exited non-zero on 'Local/67887389XX@from-internal-0000362c;2' in macro 'outisbusy' [2013-05-28 10:16:02] VERBOSE[22081] pbx.c: == Spawn extension (from-internal, 67887389XX, 7) exited non-zero on 'Local/67887389XX@from-internal-0000362c;2' [2013-05-28 10:16:02] VERBOSE[22081] pbx.c: -- Executing [h@from-internal:1] Hangup("Local/67887389XX@from-internal-0000362c;2", "") in new stack [2013-05-28 10:16:02] VERBOSE[22081] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'Local/67887389XX@from-internal-0000362c;2' [2013-05-28 10:16:02] VERBOSE[22079] app_dial.c: == Everyone is busy/congested at this time (1:0/1/0) [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-dial:8] Set("SIP/40469999XX-0000051f", "DIALSTATUS=CONGESTION") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-dial:9] GosubIf("SIP/40469999XX-0000051f", "0?CONGESTION,1") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:24] Goto("SIP/40469999XX-0000051f", "nextstep") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Goto (from-did-direct,801,26) [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:26] Set("SIP/40469999XX-0000051f", "RingGroupMethod=") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:27] GotoIf("SIP/40469999XX-0000051f", "0?nodest") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:28] Set("SIP/40469999XX-0000051f", "__NODEST=") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:29] Set("SIP/40469999XX-0000051f", "__PICKUPMARK=") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:30] Macro("SIP/40469999XX-0000051f", "blkvm-clr,") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-blkvm-clr:1] Set("SIP/40469999XX-0000051f", "SHARED(BLKVM,SIP/40469999XX-0000051f)=") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-blkvm-clr:2] Set("SIP/40469999XX-0000051f", "GOSUB_RETVAL=") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-blkvm-clr:3] MacroExit("SIP/40469999XX-0000051f", "") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:31] Set("SIP/40469999XX-0000051f", "DIALSTATUS=CHANUNAVAIL") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [801@from-did-direct:32] Goto("SIP/40469999XX-0000051f", "ext-local,801,dest") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Goto (ext-local,801,3) [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [801@ext-local:3] Set("SIP/40469999XX-0000051f", "__PICKUPMARK=") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [801@ext-local:4] Macro("SIP/40469999XX-0000051f", "vm,801,CHANUNAVAIL,RETURN") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-vm:1] Macro("SIP/40469999XX-0000051f", "user-callerid,SKIPTTL") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:1] Set("SIP/40469999XX-0000051f", "AMPUSER=72727241XX") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/40469999XX-0000051f", "0?report") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/40469999XX-0000051f", "0?Set(REALCALLERIDNUM=72727241XX)") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:4] Set("SIP/40469999XX-0000051f", "AMPUSER=") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:5] Set("SIP/40469999XX-0000051f", "AMPUSERCIDNAME=") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/40469999XX-0000051f", "1?report") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Goto (macro-user-callerid,s,13) [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:13] GotoIf("SIP/40469999XX-0000051f", "1?continue") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Goto (macro-user-callerid,s,26) [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:26] Set("SIP/40469999XX-0000051f", "CALLERID(number)=72727241XX") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:27] Set("SIP/40469999XX-0000051f", "CALLERID(name)=CLEARWATER FL") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-user-callerid:28] Set("SIP/40469999XX-0000051f", "CHANNEL(language)=en") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-vm:2] Set("SIP/40469999XX-0000051f", "VMGAIN=""") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-vm:3] Macro("SIP/40469999XX-0000051f", "blkvm-check,") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-blkvm-check:1] Set("SIP/40469999XX-0000051f", "GOSUB_RETVAL=") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-blkvm-check:2] ExecIf("SIP/40469999XX-0000051f", "0?Set(GOSUB_RETVAL=TRUE)") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-blkvm-check:3] MacroExit("SIP/40469999XX-0000051f", "") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-vm:4] GotoIf("SIP/40469999XX-0000051f", "1?vmx,1") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Goto (macro-vm,vmx,1) [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [vmx@macro-vm:1] Set("SIP/40469999XX-0000051f", "MEXTEN=801") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [vmx@macro-vm:2] Set("SIP/40469999XX-0000051f", "MMODE=CHANUNAVAIL") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [vmx@macro-vm:3] Set("SIP/40469999XX-0000051f", "RETVM=RETURN") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [vmx@macro-vm:4] Set("SIP/40469999XX-0000051f", "MODE=unavail") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [vmx@macro-vm:5] GotoIf("SIP/40469999XX-0000051f", "1?chknomsg") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Goto (macro-vm,vmx,8) [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [vmx@macro-vm:8] GotoIf("SIP/40469999XX-0000051f", "0?s-CHANUNAVAIL,1") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [vmx@macro-vm:9] GotoIf("SIP/40469999XX-0000051f", "1?notdirect") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Goto (macro-vm,vmx,11) [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [vmx@macro-vm:11] NoOp("SIP/40469999XX-0000051f", "Checking if ext 801 is enabled: ") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [vmx@macro-vm:12] GotoIf("SIP/40469999XX-0000051f", "1?s-CHANUNAVAIL,1") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Goto (macro-vm,s-CHANUNAVAIL,1) [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s-CHANUNAVAIL@macro-vm:1] Macro("SIP/40469999XX-0000051f", "get-vmcontext,801") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-get-vmcontext:1] Set("SIP/40469999XX-0000051f", "VMCONTEXT=default") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-get-vmcontext:2] GotoIf("SIP/40469999XX-0000051f", "0?200:300") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Goto (macro-get-vmcontext,s,300) [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s@macro-get-vmcontext:300] NoOp("SIP/40469999XX-0000051f", "") in new stack [2013-05-28 10:16:02] VERBOSE[22079] pbx.c: -- Executing [s-CHANUNAVAIL@macro-vm:2] VoiceMail("SIP/40469999XX-0000051f", "801@default,u""") in new stack [2013-05-28 10:16:02] VERBOSE[22079] file.c: -- Playing 'vm-theperson.ulaw' (language 'en') [2013-05-28 10:16:04] VERBOSE[22079] file.c: -- Playing 'digits/8.ulaw' (language 'en') [2013-05-28 10:16:04] VERBOSE[22079] file.c: -- Playing 'digits/0.ulaw' (language 'en') [2013-05-28 10:16:05] VERBOSE[22079] file.c: -- Playing 'digits/1.ulaw' (language 'en') [2013-05-28 10:16:06] NOTICE[22087] manager.c: Seems to have passed...

Problem is nothing to do with dialing in from the IVR, that’s working fine.

[2013-05-28 10:15:58] VERBOSE[22081] app_dial.c: -- Called SIP/cbeyond/67887389XX
[2013-05-28 10:15:58] VERBOSE[22081] app_dial.c: == Everyone is busy/congested at this time (1:0/0/1)

Your outbound call isn’t working. Do you need a 1 in front of the number? Do you need an accountcode, RPID, or some other value set to get out? If not, look at SIP debug or ask your provider why the call is failing.

Like I said, if dialing the DID from an inside line on the same PBX. The call goes through as it should.

Just when calling from an external device, not on the same network, then it gives the Congestion/Busy message. I will check with the provider to see if they can figure our why it’s not working, this is a new provider I’m working with, so I’m not sure what their policy is. I’m used to working with Vitelity, and I’ve never had any problems routing calls to external devices with them.

Thanks to all for the feedback. If you have any more idea’s please let me know.