IVR Works - but only once?

shelzmik · December 2, 2011, 7:06pm

I am 100% brand new to FreePBX and have PAIF Purple installed. And LOVE it by the way.

So, I have gotten some of the initial setup taken care of and it works well. However, I am now trying to work with my first IVR. Basically, I have a very simple IVR to start.

I have 3 extensions for the time being. The IVR should pickup and offers the caller the option to enter an extension and get to that person. They can also press # for the directory, or 8 to repeat the menu again.

I added the inbound route appropriately and it actually works…but only one time. It will work the first time, but when I hang up and then try to call back to test the other features, I can see on the status monitor that the call is coming in, but FreePBX does not pick up and then of course it goes to Google Voice voicemail. Anything that I am possibly doing wrong here?

Here is an image of the IVR setup.

Thanks!

wdroush · December 2, 2011, 10:07pm

What is the output of your Asterisk command line during the 2nd call (run “asterisk -rvvv”)?

shelzmik · December 2, 2011, 10:14pm

Do I run this from the Asterisk CLI? Because if so, I get:

No such command ‘asterisk -rvvv’ (type ‘core show help asterisk -rvvv’ for other possible commands)

Mike

wdroush · December 2, 2011, 11:08pm

haha, no you run that to get to the CLI, what is your CLI output during the inbound call?

shelzmik · December 5, 2011, 4:36pm

I was referring to the Asterisk CLI that can be found in the Left Navigation menu in Free PBX. I get nothing displaying on this page when a call is coming in because it only has a textbox asking me for a command.

I did just try to call and I can see on system status that there is a call coming in; however, I was not given the IVR, nor did it even ring my extension. I checked the logs and this is what I saw (numbers changed for obvious reasons):

[2011-12-05 11:13:51] VERBOSE[2221] pbx.c: – Executing [[email protected]@googlein:1] NoOp(“Gtalk/+15405551212-1bf5”, “Receiving GoogleVoice call”) in new stack
[2011-12-05 11:13:51] VERBOSE[2221] pbx.c: – Executing [[email protected]@googlein:2] Set(“Gtalk/+15405551212-1bf5”, “CALLERID(name)=+15405551212”) in new stack
[2011-12-05 11:13:51] VERBOSE[2221] pbx.c: – Executing [[email protected]@googlein:3] GotoIf(“Gtalk/+15405551212-1bf5”, “0?notrim”) in new stack
[2011-12-05 11:13:51] VERBOSE[2221] pbx.c: – Executing [[email protected]@googlein:4] Set(“Gtalk/+15405551212-1bf5”, “CALLERID(name)=5405551212”) in new stack
[2011-12-05 11:13:51] VERBOSE[2221] pbx.c: – Executing [[email protected]@googlein:5] Set(“Gtalk/+15405551212-1bf5”, “CALLERID(number)=5405551212”) in new stack
[2011-12-05 11:13:51] VERBOSE[2221] pbx.c: – Executing [[email protected]@googlein:6] Answer(“Gtalk/+15405551212-1bf5”, “”) in new stack
[2011-12-05 11:13:52] VERBOSE[2221] pbx.c: – Executing [[email protected]@googlein:7] Wait(“Gtalk/+15405551212-1bf5”, “1”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [[email protected]@googlein:8] SendDTMF(“Gtalk/+15405551212-1bf5”, “1”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [[email protected]@googlein:9] Goto(“Gtalk/+15405551212-1bf5”, “from-trunk,5406751234,1”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Goto (from-trunk,5406751234,1)
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [5406751234@from-trunk:1] Set(“Gtalk/+15405551212-1bf5”, “__FROM_DID=5406751234”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [5406751234@from-trunk:2] Gosub(“Gtalk/+15405551212-1bf5”, “app-blacklist-check,s,1”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“Gtalk/+15405551212-1bf5”, “0?blacklisted”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [s@app-blacklist-check:2] Set(“Gtalk/+15405551212-1bf5”, “CALLED_BLACKLIST=1”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [s@app-blacklist-check:3] Return(“Gtalk/+15405551212-1bf5”, “”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [5406751234@from-trunk:3] Gosub(“Gtalk/+15405551212-1bf5”, “cidlookup,cidlookup_1,1”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [cidlookup_1@cidlookup:1] GotoIf(“Gtalk/+15405551212-1bf5”, “1?cidlookup,cidlookup_return,1”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Goto (cidlookup,cidlookup_return,1)
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [cidlookup_return@cidlookup:1] ExecIf(“Gtalk/+15405551212-1bf5”, “1?Set(CALLERID(name)=ROANOKE, VA)”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [cidlookup_return@cidlookup:2] Return(“Gtalk/+15405551212-1bf5”, “”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [5406751234@from-trunk:4] ExecIf(“Gtalk/+15405551212-1bf5”, “0 ?Set(CALLERID(name)=5405551212)”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [5406751234@from-trunk:5] Set(“Gtalk/+15405551212-1bf5”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [5406751234@from-trunk:6] Set(“Gtalk/+15405551212-1bf5”, “CALLERPRES()=allowed_not_screened”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [5406751234@from-trunk:7] Goto(“Gtalk/+15405551212-1bf5”, “ivr-2,s,1”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Goto (ivr-2,s,1)
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [s@ivr-2:1] Set(“Gtalk/+15405551212-1bf5”, “MSG=custom/basic-ivr”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [s@ivr-2:2] Set(“Gtalk/+15405551212-1bf5”, “LOOPCOUNT=0”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [s@ivr-2:3] Set(“Gtalk/+15405551212-1bf5”, “__DIR-CONTEXT=”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [s@ivr-2:4] Set(“Gtalk/+15405551212-1bf5”, “_IVR_CONTEXT_ivr-2=”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [s@ivr-2:5] Set(“Gtalk/+15405551212-1bf5”, “_IVR_CONTEXT=ivr-2”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [s@ivr-2:6] GotoIf(“Gtalk/+15405551212-1bf5”, “1?begin”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Goto (ivr-2,s,9)
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [s@ivr-2:9] Set(“Gtalk/+15405551212-1bf5”, “TIMEOUT(digit)=3”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] func_timeout.c: – Digit timeout set to 3.000
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [s@ivr-2:10] Set(“Gtalk/+15405551212-1bf5”, “TIMEOUT(response)=10”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] func_timeout.c: – Response timeout set to 10.000
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [s@ivr-2:11] Set(“Gtalk/+15405551212-1bf5”, “__IVR_RETVM=”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] pbx.c: – Executing [s@ivr-2:12] ExecIf(“Gtalk/+15405551212-1bf5”, “1?Background(custom/basic-ivr)”) in new stack
[2011-12-05 11:13:53] VERBOSE[2221] file.c: – <Gtalk/+15405551212-1bf5> Playing ‘custom/basic-ivr.slin’ (language ‘en’)
[2011-12-05 11:14:06] VERBOSE[2221] pbx.c: == Spawn extension (ivr-2, s, 12) exited non-zero on ‘Gtalk/+15405551212-1bf5’
[2011-12-05 11:14:06] VERBOSE[2221] pbx.c: – Executing [h@ivr-2:1] Hangup(“Gtalk/+15405551212-1bf5”, “”) in new stack
[2011-12-05 11:14:06] VERBOSE[2221] pbx.c: == Spawn extension (ivr-2, h, 1) exited non-zero on ‘Gtalk/+15405551212-1bf5’

And I called it back and this time the IVR did pick up and this is what I see in the logs:

[2011-12-05 11:24:09] VERBOSE[2489] pbx.c: – Executing [[email protected]@googlein:1] NoOp(“Gtalk/+15405551212-f85b”, “Receiving GoogleVoice call”) in new stack
[2011-12-05 11:24:09] VERBOSE[2489] pbx.c: – Executing [[email protected]@googlein:2] Set(“Gtalk/+15405551212-f85b”, “CALLERID(name)=+15405551212”) in new stack
[2011-12-05 11:24:09] VERBOSE[2489] pbx.c: – Executing [[email protected]@googlein:3] GotoIf(“Gtalk/+15405551212-f85b”, “0?notrim”) in new stack
[2011-12-05 11:24:09] VERBOSE[2489] pbx.c: – Executing [[email protected]@googlein:4] Set(“Gtalk/+15405551212-f85b”, “CALLERID(name)=5405551212”) in new stack
[2011-12-05 11:24:09] VERBOSE[2489] pbx.c: – Executing [[email protected]@googlein:5] Set(“Gtalk/+15405551212-f85b”, “CALLERID(number)=5405551212”) in new stack
[2011-12-05 11:24:09] VERBOSE[2489] pbx.c: – Executing [[email protected]@googlein:6] Answer(“Gtalk/+15405551212-f85b”, “”) in new stack
[2011-12-05 11:24:10] VERBOSE[2489] pbx.c: – Executing [[email protected]@googlein:7] Wait(“Gtalk/+15405551212-f85b”, “1”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [[email protected]@googlein:8] SendDTMF(“Gtalk/+15405551212-f85b”, “1”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [[email protected]@googlein:9] Goto(“Gtalk/+15405551212-f85b”, “from-trunk,5406751234,1”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Goto (from-trunk,5406751234,1)
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [5406751234@from-trunk:1] Set(“Gtalk/+15405551212-f85b”, “__FROM_DID=5406751234”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [5406751234@from-trunk:2] Gosub(“Gtalk/+15405551212-f85b”, “app-blacklist-check,s,1”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“Gtalk/+15405551212-f85b”, “0?blacklisted”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [s@app-blacklist-check:2] Set(“Gtalk/+15405551212-f85b”, “CALLED_BLACKLIST=1”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [s@app-blacklist-check:3] Return(“Gtalk/+15405551212-f85b”, “”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [5406751234@from-trunk:3] Gosub(“Gtalk/+15405551212-f85b”, “cidlookup,cidlookup_1,1”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [cidlookup_1@cidlookup:1] GotoIf(“Gtalk/+15405551212-f85b”, “1?cidlookup,cidlookup_return,1”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Goto (cidlookup,cidlookup_return,1)
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [cidlookup_return@cidlookup:1] ExecIf(“Gtalk/+15405551212-f85b”, “1?Set(CALLERID(name)=ROANOKE, VA)”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [cidlookup_return@cidlookup:2] Return(“Gtalk/+15405551212-f85b”, “”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [5406751234@from-trunk:4] ExecIf(“Gtalk/+15405551212-f85b”, “0 ?Set(CALLERID(name)=5405551212)”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [5406751234@from-trunk:5] Set(“Gtalk/+15405551212-f85b”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [5406751234@from-trunk:6] Set(“Gtalk/+15405551212-f85b”, “CALLERPRES()=allowed_not_screened”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [5406751234@from-trunk:7] Goto(“Gtalk/+15405551212-f85b”, “ivr-2,s,1”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Goto (ivr-2,s,1)
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [s@ivr-2:1] Set(“Gtalk/+15405551212-f85b”, “MSG=custom/basic-ivr”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [s@ivr-2:2] Set(“Gtalk/+15405551212-f85b”, “LOOPCOUNT=0”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [s@ivr-2:3] Set(“Gtalk/+15405551212-f85b”, “__DIR-CONTEXT=”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [s@ivr-2:4] Set(“Gtalk/+15405551212-f85b”, “_IVR_CONTEXT_ivr-2=”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [s@ivr-2:5] Set(“Gtalk/+15405551212-f85b”, “_IVR_CONTEXT=ivr-2”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [s@ivr-2:6] GotoIf(“Gtalk/+15405551212-f85b”, “1?begin”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Goto (ivr-2,s,9)
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [s@ivr-2:9] Set(“Gtalk/+15405551212-f85b”, “TIMEOUT(digit)=3”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] func_timeout.c: – Digit timeout set to 3.000
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [s@ivr-2:10] Set(“Gtalk/+15405551212-f85b”, “TIMEOUT(response)=10”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] func_timeout.c: – Response timeout set to 10.000
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [s@ivr-2:11] Set(“Gtalk/+15405551212-f85b”, “__IVR_RETVM=”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] pbx.c: – Executing [s@ivr-2:12] ExecIf(“Gtalk/+15405551212-f85b”, “1?Background(custom/basic-ivr)”) in new stack
[2011-12-05 11:24:11] VERBOSE[2489] file.c: – <Gtalk/+15405551212-f85b> Playing ‘custom/basic-ivr.slin’ (language ‘en’)
[2011-12-05 11:24:26] WARNING[2489] func_db.c: DB_DELETE requires an argument, DB_DELETE(/)
[2011-12-05 11:24:26] VERBOSE[2489] pbx.c: – Executing [#@ivr-2:1] NoOp(“Gtalk/+15405551212-f85b”, “Deleting: “) in new stack
[2011-12-05 11:24:26] VERBOSE[2489] pbx.c: – Executing [#@ivr-2:2] Set(“Gtalk/+15405551212-f85b”, “__NODEST=”) in new stack
[2011-12-05 11:24:26] VERBOSE[2489] pbx.c: – Executing [#@ivr-2:3] GotoIf(“Gtalk/+15405551212-f85b”, “1?app-pbdirectory,pbdirectory,1:,return,1”) in new stack
[2011-12-05 11:24:26] VERBOSE[2489] pbx.c: – Goto (app-pbdirectory,pbdirectory,1)
[2011-12-05 11:24:26] VERBOSE[2489] pbx.c: – Executing [pbdirectory@app-pbdirectory:1] Answer(“Gtalk/+15405551212-f85b”, “”) in new stack
[2011-12-05 11:24:26] VERBOSE[2489] pbx.c: – Executing [pbdirectory@app-pbdirectory:2] Wait(“Gtalk/+15405551212-f85b”, “1”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Executing [pbdirectory@app-pbdirectory:3] Macro(“Gtalk/+15405551212-f85b”, “user-callerid,”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Executing [s@macro-user-callerid:1] Set(“Gtalk/+15405551212-f85b”, “AMPUSER=5405551212”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“Gtalk/+15405551212-f85b”, “0?report”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“Gtalk/+15405551212-f85b”, “1?Set(REALCALLERIDNUM=5405551212)”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Executing [s@macro-user-callerid:4] Set(“Gtalk/+15405551212-f85b”, “AMPUSER=”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Executing [s@macro-user-callerid:5] Set(“Gtalk/+15405551212-f85b”, “AMPUSERCIDNAME=”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“Gtalk/+15405551212-f85b”, “1?report”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Goto (macro-user-callerid,s,10)
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Executing [s@macro-user-callerid:10] GotoIf(“Gtalk/+15405551212-f85b”, “0?continue”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Executing [s@macro-user-callerid:11] Set(“Gtalk/+15405551212-f85b”, “__TTL=64”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“Gtalk/+15405551212-f85b”, “1?continue”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Goto (macro-user-callerid,s,19)
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Executing [s@macro-user-callerid:19] Set(“Gtalk/+15405551212-f85b”, “CALLERID(number)=5405551212”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Executing [s@macro-user-callerid:20] Set(“Gtalk/+15405551212-f85b”, “CALLERID(name)=ROANOKE, VA”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Executing [s@macro-user-callerid:21] NoOp(“Gtalk/+15405551212-f85b”, “Using CallerID “ROANOKE, VA” <5405551212>”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] pbx.c: – Executing [pbdirectory@app-pbdirectory:4] AGI(“Gtalk/+15405551212-f85b”, “pbdirectory”) in new stack
[2011-12-05 11:24:27] VERBOSE[2489] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/pbdirectory
[2011-12-05 11:24:27] VERBOSE[2489] res_agi.c: pbdirectory: test
[2011-12-05 11:24:27] VERBOSE[2489] res_agi.c: – Playing ‘pbdirectory/welcome-to-phonebook’ (escape_digits=) (sample_offset 0)
[2011-12-05 11:24:29] VERBOSE[2489] res_agi.c: pbdirectory: start loop
[2011-12-05 11:24:29] VERBOSE[2489] res_agi.c: pbdirectory: loop = 0
[2011-12-05 11:24:29] VERBOSE[2489] file.c: – <Gtalk/+15405551212-f85b> Playing ‘pbdirectory/first-three-letters-entry.slin’ (language ‘en’)
[2011-12-05 11:24:36] VERBOSE[2489] res_agi.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[2011-12-05 11:24:38] VERBOSE[2489] res_agi.c: pbdirectory: loop = 1
[2011-12-05 11:24:38] VERBOSE[2489] file.c: – <Gtalk/+15405551212-f85b> Playing ‘pbdirectory/first-three-letters-entry.slin’ (language ‘en’)
[2011-12-05 11:24:44] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘letters/m’ (language ‘en’)
[2011-12-05 11:24:44] VERBOSE[2489] res_agi.c: – Playing ‘letters/m’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:44] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘letters/i’ (language ‘en’)
[2011-12-05 11:24:44] VERBOSE[2489] res_agi.c: – Playing ‘letters/i’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:45] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘letters/k’ (language ‘en’)
[2011-12-05 11:24:45] VERBOSE[2489] res_agi.c: – Playing ‘letters/k’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:46] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘letters/e’ (language ‘en’)
[2011-12-05 11:24:46] VERBOSE[2489] res_agi.c: – Playing ‘letters/e’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:46] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘letters/space’ (language ‘en’)
[2011-12-05 11:24:46] VERBOSE[2489] res_agi.c: – Playing ‘letters/space’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:47] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘letters/m’ (language ‘en’)
[2011-12-05 11:24:47] VERBOSE[2489] res_agi.c: – Playing ‘letters/m’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:48] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘letters/i’ (language ‘en’)
[2011-12-05 11:24:48] VERBOSE[2489] res_agi.c: – Playing ‘letters/i’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:48] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘letters/l’ (language ‘en’)
[2011-12-05 11:24:48] VERBOSE[2489] res_agi.c: – Playing ‘letters/l’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:49] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘letters/l’ (language ‘en’)
[2011-12-05 11:24:49] VERBOSE[2489] res_agi.c: – Playing ‘letters/l’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:50] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘letters/e’ (language ‘en’)
[2011-12-05 11:24:50] VERBOSE[2489] res_agi.c: – Playing ‘letters/e’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:50] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘letters/r’ (language ‘en’)
[2011-12-05 11:24:50] VERBOSE[2489] res_agi.c: – Playing ‘letters/r’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:51] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘pbdirectory/if-correct-press’ (language ‘en’)
[2011-12-05 11:24:51] VERBOSE[2489] res_agi.c: – Playing ‘pbdirectory/if-correct-press’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:53] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘digits/1’ (language ‘en’)
[2011-12-05 11:24:53] VERBOSE[2489] res_agi.c: – Playing ‘digits/1’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:53] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘pbdirectory/if-incorrect-press’ (language ‘en’)
[2011-12-05 11:24:53] VERBOSE[2489] res_agi.c: – Playing ‘pbdirectory/if-incorrect-press’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:55] VERBOSE[2489] res_agi.c: pbdirectory: – Playing ‘digits/star’ (language ‘en’)
[2011-12-05 11:24:55] VERBOSE[2489] res_agi.c: – Playing ‘digits/star’ (escape_digits=1*) (sample_offset 0)
[2011-12-05 11:24:56] VERBOSE[2489] res_agi.c: – <Gtalk/+15405551212-f85b>AGI Script pbdirectory completed, returning 0
[2011-12-05 11:24:56] VERBOSE[2489] pbx.c: – Executing [pbdirectory@app-pbdirectory:5] GotoIf(“Gtalk/+15405551212-f85b”, “0?hangup,1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2489] pbx.c: – Executing [pbdirectory@app-pbdirectory:6] NoOp(“Gtalk/+15405551212-f85b”, “Got number to dial: 224”) in new stack
[2011-12-05 11:24:56] VERBOSE[2489] pbx.c: – Executing [pbdirectory@app-pbdirectory:7] Dial(“Gtalk/+15405551212-f85b”, “Local/224@from-internal/n,”) in new stack
[2011-12-05 11:24:56] VERBOSE[2489] app_dial.c: – Called Local/224@from-internal/n
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [224@from-internal:1] Macro(“Local/224@from-internal-8b47;2”, “exten-vm,224,224”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:1] Macro(“Local/224@from-internal-8b47;2”, “user-callerid,”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-user-callerid:1] Set(“Local/224@from-internal-8b47;2”, “AMPUSER=5405551212”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“Local/224@from-internal-8b47;2”, “1?report”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-user-callerid,s,10)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-user-callerid:10] GotoIf(“Local/224@from-internal-8b47;2”, “0?continue”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-user-callerid:11] Set(“Local/224@from-internal-8b47;2”, “__TTL=63”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“Local/224@from-internal-8b47;2”, “1?continue”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-user-callerid,s,19)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-user-callerid:19] Set(“Local/224@from-internal-8b47;2”, “CALLERID(number)=5405551212”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-user-callerid:20] Set(“Local/224@from-internal-8b47;2”, “CALLERID(name)=ROANOKE, VA”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-user-callerid:21] NoOp(“Local/224@from-internal-8b47;2”, “Using CallerID “ROANOKE, VA” <5405551212>”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:2] Set(“Local/224@from-internal-8b47;2”, “RingGroupMethod=none”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:3] Set(“Local/224@from-internal-8b47;2”, “VMBOX=224”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:4] Set(“Local/224@from-internal-8b47;2”, “__EXTTOCALL=224”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:5] Set(“Local/224@from-internal-8b47;2”, “CFUEXT=”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:6] Set(“Local/224@from-internal-8b47;2”, “CFBEXT=”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:7] Set(“Local/224@from-internal-8b47;2”, “RT=15”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:8] Macro(“Local/224@from-internal-8b47;2”, “record-enable,224,IN”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-record-enable:1] GotoIf(“Local/224@from-internal-8b47;2”, “1?check”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-record-enable,s,4)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-record-enable:4] ExecIf(“Local/224@from-internal-8b47;2”, “0?MacroExit()”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-record-enable:5] GotoIf(“Local/224@from-internal-8b47;2”, “0?Group:OUT”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-record-enable,s,15)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-record-enable:15] GotoIf(“Local/224@from-internal-8b47;2”, “1?IN”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-record-enable,s,20)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-record-enable:20] ExecIf(“Local/224@from-internal-8b47;2”, “1?MacroExit()”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:9] Macro(“Local/224@from-internal-8b47;2”, “dial-one,15,tr,224”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:1] Set(“Local/224@from-internal-8b47;2”, “DEXTEN=224”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:2] Set(“Local/224@from-internal-8b47;2”, “DIALSTATUS_CW=”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:3] GosubIf(“Local/224@from-internal-8b47;2”, “0?screen,1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:4] GosubIf(“Local/224@from-internal-8b47;2”, “0?cf,1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:5] GotoIf(“Local/224@from-internal-8b47;2”, “1?skip1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-dial-one,s,8)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:8] GotoIf(“Local/224@from-internal-8b47;2”, “0?nodial”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:9] GotoIf(“Local/224@from-internal-8b47;2”, “0?continue”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:10] Set(“Local/224@from-internal-8b47;2”, “EXTHASCW=ENABLED”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:11] GotoIf(“Local/224@from-internal-8b47;2”, “0?next1:cwinusebusy”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-dial-one,s,23)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:23] GotoIf(“Local/224@from-internal-8b47;2”, “1?next3:continue”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-dial-one,s,24)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:24] ExecIf(“Local/224@from-internal-8b47;2”, “0?Set(DIALSTATUS_CW=BUSY)”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:25] GotoIf(“Local/224@from-internal-8b47;2”, “0?nodial”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:26] GosubIf(“Local/224@from-internal-8b47;2”, “1?dstring,1:dlocal,1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [dstring@macro-dial-one:1] Set(“Local/224@from-internal-8b47;2”, “DSTRING=”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [dstring@macro-dial-one:2] Set(“Local/224@from-internal-8b47;2”, “DEVICES=224”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [dstring@macro-dial-one:3] ExecIf(“Local/224@from-internal-8b47;2”, “0?Return()”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [dstring@macro-dial-one:4] ExecIf(“Local/224@from-internal-8b47;2”, “0?Set(DEVICES=24)”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [dstring@macro-dial-one:5] Set(“Local/224@from-internal-8b47;2”, “LOOPCNT=1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [dstring@macro-dial-one:6] Set(“Local/224@from-internal-8b47;2”, “ITER=1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [dstring@macro-dial-one:7] Set(“Local/224@from-internal-8b47;2”, “THISDIAL=SIP/224”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [dstring@macro-dial-one:8] GosubIf(“Local/224@from-internal-8b47;2”, “1?zap2dahdi,1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [zap2dahdi@macro-dial-one:1] ExecIf(“Local/224@from-internal-8b47;2”, “0?Return()”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [zap2dahdi@macro-dial-one:2] Set(“Local/224@from-internal-8b47;2”, “NEWDIAL=”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [zap2dahdi@macro-dial-one:3] Set(“Local/224@from-internal-8b47;2”, “LOOPCNT2=1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [zap2dahdi@macro-dial-one:4] Set(“Local/224@from-internal-8b47;2”, “ITER2=1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [zap2dahdi@macro-dial-one:5] Set(“Local/224@from-internal-8b47;2”, “THISPART2=SIP/224”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [zap2dahdi@macro-dial-one:6] ExecIf(“Local/224@from-internal-8b47;2”, “0?Set(THISPART2=DAHDI/224)”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [zap2dahdi@macro-dial-one:7] Set(“Local/224@from-internal-8b47;2”, “NEWDIAL=SIP/224&”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [zap2dahdi@macro-dial-one:8] Set(“Local/224@from-internal-8b47;2”, “ITER2=2”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [zap2dahdi@macro-dial-one:9] GotoIf(“Local/224@from-internal-8b47;2”, “0?begin2”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [zap2dahdi@macro-dial-one:10] Set(“Local/224@from-internal-8b47;2”, “THISDIAL=SIP/224”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [zap2dahdi@macro-dial-one:11] Return(“Local/224@from-internal-8b47;2”, “”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [dstring@macro-dial-one:9] Set(“Local/224@from-internal-8b47;2”, “DSTRING=SIP/224&”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [dstring@macro-dial-one:10] Set(“Local/224@from-internal-8b47;2”, “ITER=2”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [dstring@macro-dial-one:11] GotoIf(“Local/224@from-internal-8b47;2”, “0?begin”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [dstring@macro-dial-one:12] Set(“Local/224@from-internal-8b47;2”, “DSTRING=SIP/224”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [dstring@macro-dial-one:13] Return(“Local/224@from-internal-8b47;2”, “”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:27] GotoIf(“Local/224@from-internal-8b47;2”, “0?nodial”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:28] GotoIf(“Local/224@from-internal-8b47;2”, “1?skiptrace”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-dial-one,s,30)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:30] Set(“Local/224@from-internal-8b47;2”, “D_OPTIONS=tr”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:31] ExecIf(“Local/224@from-internal-8b47;2”, “0?SIPAddHeader(Alert-Info: )”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:32] ExecIf(“Local/224@from-internal-8b47;2”, “0?SIPAddHeader()”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:33] ExecIf(“Local/224@from-internal-8b47;2”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:34] GosubIf(“Local/224@from-internal-8b47;2”, “0?qwait,1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:35] Set(“Local/224@from-internal-8b47;2”, “__CWIGNORE=”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:36] Set(“Local/224@from-internal-8b47;2”, “__KEEPCID=TRUE”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:37] Dial(“Local/224@from-internal-8b47;2”, “SIP/224,15,tr”) in new stack
[2011-12-05 11:24:56] WARNING[2545] app_dial.c: Unable to create channel of type ‘SIP’ (cause 20 - Unknown)
[2011-12-05 11:24:56] VERBOSE[2545] app_dial.c: == Everyone is busy/congested at this time (1:0/0/1)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:38] ExecIf(“Local/224@from-internal-8b47;2”, “0?Set(DIALSTATUS=)”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:39] GosubIf(“Local/224@from-internal-8b47;2”, “0?s-CHANUNAVAIL,1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-dial-one:40] MacroExit(“Local/224@from-internal-8b47;2”, “”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:10] GotoIf(“Local/224@from-internal-8b47;2”, “0?exit”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:11] Set(“Local/224@from-internal-8b47;2”, “SV_DIALSTATUS=CHANUNAVAIL”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:12] GosubIf(“Local/224@from-internal-8b47;2”, “0?docfu,1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:13] GosubIf(“Local/224@from-internal-8b47;2”, “0?docfb,1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:14] Set(“Local/224@from-internal-8b47;2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:15] NoOp(“Local/224@from-internal-8b47;2”, “Voicemail is ‘224’”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:16] GotoIf(“Local/224@from-internal-8b47;2”, “0?s-CHANUNAVAIL,1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:17] NoOp(“Local/224@from-internal-8b47;2”, “Sending to Voicemail box 224”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-exten-vm:18] Macro(“Local/224@from-internal-8b47;2”, “vm,224,CHANUNAVAIL,”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-vm:1] Macro(“Local/224@from-internal-8b47;2”, “user-callerid,SKIPTTL”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-user-callerid:1] Set(“Local/224@from-internal-8b47;2”, “AMPUSER=5405551212”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“Local/224@from-internal-8b47;2”, “1?report”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-user-callerid,s,10)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-user-callerid:10] GotoIf(“Local/224@from-internal-8b47;2”, “1?continue”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-user-callerid,s,19)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-user-callerid:19] Set(“Local/224@from-internal-8b47;2”, “CALLERID(number)=5405551212”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-user-callerid:20] Set(“Local/224@from-internal-8b47;2”, “CALLERID(name)=ROANOKE, VA”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-user-callerid:21] NoOp(“Local/224@from-internal-8b47;2”, “Using CallerID “ROANOKE, VA” <5405551212>”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-vm:2] Set(“Local/224@from-internal-8b47;2”, “VMGAIN=”””) in new stack
[2011-12-05 11:24:56] WARNING[2545] func_db.c: DB requires an argument, DB(/)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-vm:3] GotoIf(“Local/224@from-internal-8b47;2”, “1?vmx,1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-vm,vmx,1)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [vmx@macro-vm:1] Set(“Local/224@from-internal-8b47;2”, “MEXTEN=224”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [vmx@macro-vm:2] Set(“Local/224@from-internal-8b47;2”, “MMODE=CHANUNAVAIL”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [vmx@macro-vm:3] Set(“Local/224@from-internal-8b47;2”, “RETVM=”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [vmx@macro-vm:4] Set(“Local/224@from-internal-8b47;2”, “MODE=unavail”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [vmx@macro-vm:5] GotoIf(“Local/224@from-internal-8b47;2”, “1?chknomsg”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-vm,vmx,7)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [vmx@macro-vm:7] GotoIf(“Local/224@from-internal-8b47;2”, “0?s-CHANUNAVAIL,1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [vmx@macro-vm:8] GotoIf(“Local/224@from-internal-8b47;2”, “1?notdirect”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-vm,vmx,10)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [vmx@macro-vm:10] NoOp(“Local/224@from-internal-8b47;2”, “Checking if ext 224 is enabled: “) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [vmx@macro-vm:11] GotoIf(“Local/224@from-internal-8b47;2”, “1?s-CHANUNAVAIL,1”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-vm,s-CHANUNAVAIL,1)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s-CHANUNAVAIL@macro-vm:1] Macro(“Local/224@from-internal-8b47;2”, “get-vmcontext,224”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-get-vmcontext:1] Set(“Local/224@from-internal-8b47;2”, “VMCONTEXT=default”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-get-vmcontext:2] GotoIf(“Local/224@from-internal-8b47;2”, “0?200:300”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Goto (macro-get-vmcontext,s,300)
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s@macro-get-vmcontext:300] NoOp(“Local/224@from-internal-8b47;2”, “”) in new stack
[2011-12-05 11:24:56] VERBOSE[2545] pbx.c: – Executing [s-CHANUNAVAIL@macro-vm:2] VoiceMail(“Local/224@from-internal-8b47;2”, “224@default,u”””) in new stack
[2011-12-05 11:24:56] VERBOSE[2489] app_dial.c: – Local/224@from-internal-8b47;1 answered Gtalk/+15405551212-f85b
[2011-12-05 11:24:56] VERBOSE[2545] file.c: – <Local/224@from-internal-8b47;2> Playing ‘vm-theperson.gsm’ (language ‘en’)
[2011-12-05 11:24:57] VERBOSE[2545] file.c: – <Local/224@from-internal-8b47;2> Playing ‘digits/2.gsm’ (language ‘en’)
[2011-12-05 11:24:58] VERBOSE[2545] file.c: – <Local/224@from-internal-8b47;2> Playing ‘digits/2.gsm’ (language ‘en’)
[2011-12-05 11:24:59] VERBOSE[2545] file.c: – <Local/224@from-internal-8b47;2> Playing ‘digits/4.gsm’ (language ‘en’)
[2011-12-05 11:24:59] VERBOSE[2545] file.c: – <Local/224@from-internal-8b47;2> Playing ‘vm-isunavail.gsm’ (language ‘en’)
[2011-12-05 11:25:00] VERBOSE[2545] file.c: – <Local/224@from-internal-8b47;2> Playing ‘vm-intro.gsm’ (language ‘en’)
[2011-12-05 11:25:06] VERBOSE[2545] file.c: – <Local/224@from-internal-8b47;2> Playing ‘beep.gsm’ (language ‘en’)
[2011-12-05 11:25:06] VERBOSE[2545] app_voicemail.c: – Recording the message
[2011-12-05 11:25:06] VERBOSE[2545] app.c: – x=0, open writing: /var/spool/asterisk/voicemail/default/224/tmp/WC6Cm4 format: wav49, 0x8eb6cc8
[2011-12-05 11:25:06] VERBOSE[2545] app.c: – x=1, open writing: /var/spool/asterisk/voicemail/default/224/tmp/WC6Cm4 format: gsm, 0x8fe4618
[2011-12-05 11:25:06] VERBOSE[2545] app.c: – x=2, open writing: /var/spool/asterisk/voicemail/default/224/tmp/WC6Cm4 format: wav, 0x8b51e28
[2011-12-05 11:25:11] NOTICE[8300] chan_sip.c: Peer ‘224’ is now Reachable. (9ms / 2000ms)
[2011-12-05 11:25:12] VERBOSE[2545] app.c: – User hung up
[2011-12-05 11:25:12] VERBOSE[2489] pbx.c: == Spawn extension (app-pbdirectory, pbdirectory, 7) exited non-zero on ‘Gtalk/+15405551212-f85b’
[2011-12-05 11:25:12] VERBOSE[2545] app_macro.c: == Spawn extension (macro-vm, s-CHANUNAVAIL, 2) exited non-zero on ‘Local/224@from-internal-8b47;2’ in macro ‘vm’
[2011-12-05 11:25:12] VERBOSE[2545] app_macro.c: == Spawn extension (macro-exten-vm, s, 18) exited non-zero on ‘Local/224@from-internal-8b47;2’ in macro ‘exten-vm’
[2011-12-05 11:25:12] VERBOSE[2545] pbx.c: == Spawn extension (from-internal, 224, 1) exited non-zero on ‘Local/224@from-internal-8b47;2’
[2011-12-05 11:25:12] VERBOSE[2545] pbx.c: – Executing [h@from-internal:1] Macro(“Local/224@from-internal-8b47;2”, “hangupcall”) in new stack
[2011-12-05 11:25:12] VERBOSE[2545] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“Local/224@from-internal-8b47;2”, “1?skiprg”) in new stack
[2011-12-05 11:25:12] VERBOSE[2545] pbx.c: – Goto (macro-hangupcall,s,4)
[2011-12-05 11:25:12] VERBOSE[2545] pbx.c: – Executing [s@macro-hangupcall:4] GotoIf(“Local/224@from-internal-8b47;2”, “1?skipblkvm”) in new stack
[2011-12-05 11:25:12] VERBOSE[2545] pbx.c: – Goto (macro-hangupcall,s,7)
[2011-12-05 11:25:12] VERBOSE[2545] pbx.c: – Executing [s@macro-hangupcall:7] GotoIf(“Local/224@from-internal-8b47;2”, “1?theend”) in new stack
[2011-12-05 11:25:12] VERBOSE[2545] pbx.c: – Goto (macro-hangupcall,s,9)
[2011-12-05 11:25:12] VERBOSE[2545] pbx.c: – Executing [s@macro-hangupcall:9] Hangup(“Local/224@from-internal-8b47;2”, “”) in new stack
[2011-12-05 11:25:12] VERBOSE[2545] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘Local/224@from-internal-8b47;2’ in macro ‘hangupcall’
[2011-12-05 11:25:12] VERBOSE[2545] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘Local/224@from-internal-8b47;2’

Also, the only thing to make a note of is that I only have 2 extensions setup and only one is usually registered, which is my cell phone (Android). During this time frame, my wifi was acting up and phone kept dropping in and out of registration. But, shouldn’t the IVR system still work, even if no phones are registered? The other times I try and it works only one time and then not again the phone is registered the whole time.

Thanks!

Mike