FreePBX 2.9.0beta2.1 Queue Issue

brian · March 14, 2011, 1:14pm

Hi All,

Running Asterisk 1.4.22

The upgrade seems to have broken the Skip Busy Agents feature.

If an agent is logged into the queue and DND set on phone and Asterisk tries to call that endpoint it will answer and go to Voicemail.

Same if the enduser is on the phone it will go to voicemail.

I’ve tried every option in the skip busy agents feature and they all behave the same.

I attach output from the asterisk console of it trying extension 107 - busy being returned and then it dialing to voicemail.

If I can provide any further information please let me know.

Regards
brian

edit!:

I pasted the console into the Log |Message box but it didn’t attach to the message.

Attached:

-- Called Local/107@from-queue/n
-- Executing [107@from-queue:1] Set("Local/107@from-queue-003c,2", "QAGENT=107") in new stack
-- Executing [107@from-queue:2] Goto("Local/107@from-queue-003c,2", "400|1") in new stack
-- Goto (from-queue,400,1)
-- Executing [400@from-queue:1] Goto("Local/107@from-queue-003c,2", "from-internal|107|1") in new stack
-- Goto (from-internal,107,1)
-- Executing [107@from-internal:1] ExecIf("Local/107@from-queue-003c,2", "0|Set|__RINGTIMER=0") in new stack
-- Executing [107@from-internal:2] Macro("Local/107@from-queue-003c,2", "exten-vm|107|107|0|0|0") in new stack
-- Executing [s@macro-exten-vm:1] Macro("Local/107@from-queue-003c,2", "user-callerid|") in new stack
-- Executing [s@macro-user-callerid:1] Set("Local/107@from-queue-003c,2", "AMPUSER=016877777") in new stack
-- Executing [s@macro-user-callerid:2] GotoIf("Local/107@from-queue-003c,2", "1?report") in new stack
-- Goto (macro-user-callerid,s,12)
-- Executing [s@macro-user-callerid:12] GotoIf("Local/107@from-queue-003c,2", "0?continue") in new stack
-- Executing [s@macro-user-callerid:13] Set("Local/107@from-queue-003c,2", "__TTL=63") in new stack
-- Executing [s@macro-user-callerid:14] GotoIf("Local/107@from-queue-003c,2", "1?continue") in new stack
-- Goto (macro-user-callerid,s,25)
-- Executing [s@macro-user-callerid:25] Set("Local/107@from-queue-003c,2", "CALLERID(number)=016877777") in new stack
-- Executing [s@macro-user-callerid:26] Set("Local/107@from-queue-003c,2", "CALLERID(name)=Brian ") in new stack
-- Executing [s@macro-exten-vm:2] Set("Local/107@from-queue-003c,2", "RingGroupMethod=none") in new stack
-- Executing [s@macro-exten-vm:3] Set("Local/107@from-queue-003c,2", "__EXTTOCALL=107") in new stack
-- Executing [s@macro-exten-vm:4] Set("Local/107@from-queue-003c,2", "__PICKUPMARK=107") in new stack
-- Executing [s@macro-exten-vm:5] Set("Local/107@from-queue-003c,2", "RT=30") in new stack
-- Executing [s@macro-exten-vm:6] Macro("Local/107@from-queue-003c,2", "record-enable|107|IN") in new stack
-- Executing [s@macro-record-enable:1] GotoIf("Local/107@from-queue-003c,2", "1?check") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing [s@macro-record-enable:4] ExecIf("Local/107@from-queue-003c,2", "0|MacroExit|") in new stack
-- Executing [s@macro-record-enable:5] GotoIf("Local/107@from-queue-003c,2", "0?Group:OUT") in new stack
-- Goto (macro-record-enable,s,14)
-- Executing [s@macro-record-enable:14] GotoIf("Local/107@from-queue-003c,2", "1?IN") in new stack
-- Goto (macro-record-enable,s,18)
-- Executing [s@macro-record-enable:18] ExecIf("Local/107@from-queue-003c,2", "1|MacroExit|") in new stack
-- Executing [s@macro-exten-vm:7] GotoIf("Local/107@from-queue-003c,2", "4?macrodial") in new stack
-- Goto (macro-exten-vm,s,13)
-- Executing [s@macro-exten-vm:13] GosubIf("Local/107@from-queue-003c,2", "0?clrheader|1") in new stack
-- Executing [s@macro-exten-vm:14] Macro("Local/107@from-queue-003c,2", "dial|30|TtrM(auto-blkvm)|107") in new stack
-- Executing [s@macro-dial:1] GotoIf("Local/107@from-queue-003c,2", "1?dial") in new stack
-- Goto (macro-dial,s,3)
-- Executing [s@macro-dial:3] AGI("Local/107@from-queue-003c,2", "dialparties.agi") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi

dialparties.agi: Starting New Dialparties.agi
== Parsing ‘/etc/asterisk/manager.conf’: Found
== Parsing ‘/etc/asterisk/manager_additional.conf’: Found
== Parsing ‘/etc/asterisk/manager_custom.conf’: Found
== Manager ‘admin’ logged on from 127.0.0.1
dialparties.agi: Caller ID name is 'Brian ’ number is ‘016877777’
– AGI Script Executing Application: (SIPAddHeader) Options: (Alert-Info:Simple-1)
dialparties.agi: Methodology of ring is ‘none’
– dialparties.agi: Added extension 107 to extension map
– dialparties.agi: Extension 107 cf is disabled
– dialparties.agi: Extension 107 do not disturb is disabled
dialparties.agi: ExtensionState: 0
dialparties.agi: Extension 107 has ExtensionState: 0
– dialparties.agi: Checking CW and CFB status for extension 107
– dialparties.agi: dbset CALLTRACE/107 to 016877777
– dialparties.agi: Filtered ARG3: 107
== Manager ‘admin’ logged off from 127.0.0.1
– AGI Script dialparties.agi completed, returning 0
– Executing [s@macro-dial:7] Dial(“Local/107@from-queue-003c,2”, “SIP/107|30|TtrM(auto-blkvm)”) in new stack
– Called 107
Extension Changed 107[ext-local] new state Ringing for Notify User 107
– Local/107@from-queue-003c,1 is ringing
Extension Changed 107[ext-local] new state Ringing for Notify User 111
Extension Changed 107[ext-local] new state Ringing for Notify User 122
Extension Changed 107[ext-local] new state Ringing for Notify User 112
Extension Changed 107[ext-local] new state Ringing for Notify User 135
Extension Changed 107[ext-local] new state Ringing for Notify User 117
Extension Changed 107[ext-local] new state Ringing for Notify User 100
Extension Changed 107[ext-local] new state Ringing for Notify User 104
– Got SIP response 486 “Busy Here” back from 192.168.1.41
– SIP/107-086a6458 is busy
== Everyone is busy/congested at this time (1:1/0/0)
– Executing [s@macro-dial:8] Set(“Local/107@from-queue-003c,2”, “DIALSTATUS=BUSY”) in new stack
Extension Changed 107[ext-local] new state Idle for Notify User 107
– Executing [s@macro-dial:9] GosubIf(“Local/107@from-queue-003c,2”, “0?BUSY|1”) in new stack
– Executing [s@macro-exten-vm:15] GotoIf(“Local/107@from-queue-003c,2”, “0?exit”) in new stack
Extension Changed 107[ext-local] new state Idle for Notify User 111
– Executing [s@macro-exten-vm:16] Set(“Local/107@from-queue-003c,2”, “SV_DIALSTATUS=BUSY”) in new stack
– Executing [s@macro-exten-vm:17] GosubIf(“Local/107@from-queue-003c,2”, “0?docfu|1”) in new stack
Extension Changed 107[ext-local] new state Idle for Notify User 122
– Executing [s@macro-exten-vm:18] GosubIf(“Local/107@from-queue-003c,2”, “0?docfb|1”) in new stack
Extension Changed 107[ext-local] new state Idle for Notify User 112
– Executing [s@macro-exten-vm:19] Set(“Local/107@from-queue-003c,2”, “DIALSTATUS=BUSY”) in new stack
– Executing [s@macro-exten-vm:20] ExecIf(“Local/107@from-queue-003c,2”, “0|MacroExit|”) in new stack
Extension Changed 107[ext-local] new state Idle for Notify User 135
Extension Changed 107[ext-local] new state Idle for Notify User 117
Extension Changed 107[ext-local] new state Idle for Notify User 100
Extension Changed 107[ext-local] new state Idle for Notify User 104
– Executing [s@macro-exten-vm:21] GotoIf(“Local/107@from-queue-003c,2”, “0?s-BUSY|1”) in new stack
– Executing [s@macro-exten-vm:22] Macro(“Local/107@from-queue-003c,2”, “vm|107|BUSY|”) in new stack
– Executing [s@macro-vm:1] Macro(“Local/107@from-queue-003c,2”, “user-callerid|SKIPTTL”) in new stack
– Executing [s@macro-user-callerid:1] Set(“Local/107@from-queue-003c,2”, “AMPUSER=016877777”) in new stack
– Executing [s@macro-user-callerid:2] GotoIf(“Local/107@from-queue-003c,2”, “1?report”) in new stack
– Goto (macro-user-callerid,s,12)
– Executing [s@macro-user-callerid:12] GotoIf(“Local/107@from-queue-003c,2”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,25)
– Executing [s@macro-user-callerid:25] Set(“Local/107@from-queue-003c,2”, “CALLERID(number)=016877777”) in new stack
– Executing [s@macro-user-callerid:26] Set(“Local/107@from-queue-003c,2”, “CALLERID(name)=M0:Brian “) in new stack
– Executing [s@macro-vm:2] Set(“Local/107@from-queue-003c,2”, “VMGAIN=”””) in new stack
– Executing [s@macro-vm:3] Macro(“Local/107@from-queue-003c,2”, “blkvm-check|”) in new stack
– Executing [s@macro-vm:4] GotoIf(“Local/107@from-queue-003c,2”, “1?vmx|1”) in new stack
– Goto (macro-vm,vmx,1)
– Executing [vmx@macro-vm:1] Set(“Local/107@from-queue-003c,2”, “MEXTEN=107”) in new stack
– Executing [vmx@macro-vm:2] Set(“Local/107@from-queue-003c,2”, “MMODE=BUSY”) in new stack
– Executing [vmx@macro-vm:3] Set(“Local/107@from-queue-003c,2”, “RETVM=”) in new stack
– Executing [vmx@macro-vm:4] Set(“Local/107@from-queue-003c,2”, “MODE=busy”) in new stack
– Executing [vmx@macro-vm:5] GotoIf(“Local/107@from-queue-003c,2”, “1?chknomsg”) in new stack
– Goto (macro-vm,vmx,8)
– Executing [vmx@macro-vm:8] GotoIf(“Local/107@from-queue-003c,2”, “0?s-BUSY|1”) in new stack
– Executing [vmx@macro-vm:9] GotoIf(“Local/107@from-queue-003c,2”, “1?notdirect”) in new stack
– Goto (macro-vm,vmx,11)
– Executing [vmx@macro-vm:11] NoOp(“Local/107@from-queue-003c,2”, "Checking if ext 107 is enabled: ") in new stack
– Executing [vmx@macro-vm:12] GotoIf(“Local/107@from-queue-003c,2”, “1?s-BUSY|1”) in new stack
– Goto (macro-vm,s-BUSY,1)
– Executing [s-BUSY@macro-vm:1] NoOp(“Local/107@from-queue-003c,2”, “BUSY voicemail”) in new stack
– Executing [s-BUSY@macro-vm:2] Macro(“Local/107@from-queue-003c,2”, “get-vmcontext|107”) in new stack
– Executing [s@macro-get-vmcontext:1] Set(“Local/107@from-queue-003c,2”, “VMCONTEXT=default”) in new stack
– Executing [s@macro-get-vmcontext:2] GotoIf(“Local/107@from-queue-003c,2”, “0?200:300”) in new stack
– Goto (macro-get-vmcontext,s,300)
– Executing [s@macro-get-vmcontext:300] NoOp(“Local/107@from-queue-003c,2”, “”) in new stack
– Executing [s-BUSY@macro-vm:3] VoiceMail(“Local/107@from-queue-003c,2”, “107@default|b”) in new stack
– Local/107@from-queue-003c,1 answered DAHDI/9-1
– Stopped music on hold on DAHDI/9-1
– <Local/107@from-queue-003c,2> Playing ‘vm-theperson’ (language ‘en’)
– <Local/107@from-queue-003c,2> Playing ‘digits/1’ (language ‘en’)

brian · March 17, 2011, 8:05pm

Hi tm2000

Sincere apologies to Philippe, I had a lot of different mailing lists open and was involved in quite a few conversations…

I really don’t know why I was using peter here as I have been a longtime freepbx user and know Philippe’s name from following him here and on other forums.

embarrassed

Brian

tm1000 · March 17, 2011, 2:09am

Not to be an ‘ass’ here but his name is Philippe. Not Peter. Just for clarification sakes.

plindheimer · March 14, 2011, 10:20pm

#4968

it’s a bug, check the new core module that should be published in the next 10 minutes.

brian · March 14, 2011, 10:21pm

Thanks Peter.

I did search the bug tracker but wasn’t searching for the right thing.

Thanks again for your time.

Brian

plindheimer · March 14, 2011, 10:53pm

I just entered that ticket from here, and put you as the author, it wasn’t there before

brian · March 14, 2011, 11:07pm

Peter,

I figured that 3 seconds after I replied to your message

I’ve updated the module and just tested it. It works perfectly.

Brian

plindheimer · March 14, 2011, 10:12pm

it’s what I mentioned.

the macro-blkvm-check is not there:

[2011-03-14 13:10:37] WARNING[3758] app_macro.c: Context 'macro-blkvm-check' for macro 'blkvm-check' lacks 's' extension, priority 1

something is not right on your system. That macro is auto-generated and should be in extensions_additional.conf, along with the one that sets it.

brian · March 14, 2011, 10:18pm

Hi Peter,

This was all working for over a year before I ran the upgrade to 2.9

from extensions_additional

[macro-blkvm-check]
include => macro-blkvm-check-custom
exten => _s-.,1,Set(GOSUB_RETVAL=${DB(${BLKVM_OVERRIDE})})
exten => _s-.,n,MacroExit()

; end of [macro-blkvm-check]

Thanks,
Brian

brian · March 14, 2011, 9:21pm

Hi Peter,

Log file attached. If you need anything else on this let me know.

Apologies it took me so long.

Thanks,
Brian

[2011-03-14 13:10:37] VERBOSE[3754] logger.c: – Local/107@from-queue-003c,1 is ringing
[2011-03-14 13:10:37] VERBOSE[3754] logger.c: – Local/107@from-queue-003c,1 is ringing
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Ringing for Notify User 111
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Ringing for Notify User 111
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Ringing for Notify User 122
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Ringing for Notify User 122
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Ringing for Notify User 112
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Ringing for Notify User 112
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Ringing for Notify User 135
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Ringing for Notify User 135
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Ringing for Notify User 117
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Ringing for Notify User 117
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Ringing for Notify User 100
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Ringing for Notify User 100
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Ringing for Notify User 104
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Ringing for Notify User 104
[2011-03-14 13:10:37] VERBOSE[23170] logger.c: – Got SIP response 486 “Busy Here” back from 192.168.1.41
[2011-03-14 13:10:37] VERBOSE[23170] logger.c: – Got SIP response 486 “Busy Here” back from 192.168.1.41
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – SIP/107-086a6458 is busy
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – SIP/107-086a6458 is busy
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: == Everyone is busy/congested at this time (1:1/0/0)
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: == Everyone is busy/congested at this time (1:1/0/0)
[2011-03-14 13:10:37] DEBUG[3754] app_queue.c: Dunno what to do with control type -1
[2011-03-14 13:10:37] DEBUG[3754] app_queue.c: Dunno what to do with control type -1
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Dial
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Dial
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-dial:8] Set(“Local/107@from-queue-003c,2”, “DIALSTATUS=BUSY”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-dial:8] Set(“Local/107@from-queue-003c,2”, “DIALSTATUS=BUSY”) in new stack
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 107
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 107
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-dial:9] GosubIf(“Local/107@from-queue-003c,2”, “0?BUSY|1”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-dial:9] GosubIf(“Local/107@from-queue-003c,2”, “0?BUSY|1”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GosubIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GosubIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Macro
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Macro
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 111
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 111
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:15] GotoIf(“Local/107@from-queue-003c,2”, “0?exit”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:15] GotoIf(“Local/107@from-queue-003c,2”, “0?exit”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:16] Set(“Local/107@from-queue-003c,2”, “SV_DIALSTATUS=BUSY”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:16] Set(“Local/107@from-queue-003c,2”, “SV_DIALSTATUS=BUSY”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] func_db.c: DB: CFU/107 not found in database.
[2011-03-14 13:10:37] DEBUG[3758] func_db.c: DB: CFU/107 not found in database.
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 122
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 122
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:17] GosubIf(“Local/107@from-queue-003c,2”, “0?docfu|1”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:17] GosubIf(“Local/107@from-queue-003c,2”, “0?docfu|1”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GosubIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GosubIf
[2011-03-14 13:10:37] DEBUG[3758] func_db.c: DB: CFU/107 not found in database.
[2011-03-14 13:10:37] DEBUG[3758] func_db.c: DB: CFU/107 not found in database.
[2011-03-14 13:10:37] DEBUG[3758] func_db.c: DB: CFB/107 not found in database.
[2011-03-14 13:10:37] DEBUG[3758] func_db.c: DB: CFB/107 not found in database.
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:18] GosubIf(“Local/107@from-queue-003c,2”, “0?docfb|1”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:18] GosubIf(“Local/107@from-queue-003c,2”, “0?docfb|1”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GosubIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GosubIf
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 112
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 112
[2011-03-14 13:10:37] DEBUG[3758] func_db.c: DB: CFB/107 not found in database.
[2011-03-14 13:10:37] DEBUG[3758] func_db.c: DB: CFB/107 not found in database.
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:19] Set(“Local/107@from-queue-003c,2”, “DIALSTATUS=BUSY”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:19] Set(“Local/107@from-queue-003c,2”, “DIALSTATUS=BUSY”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 135
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 135
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 117
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 117
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 100
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 100
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 104
[2011-03-14 13:10:37] VERBOSE[23163] logger.c: Extension Changed 107[ext-local] new state Idle for Notify User 104
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:20] ExecIf(“Local/107@from-queue-003c,2”, “0|MacroExit|”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:20] ExecIf(“Local/107@from-queue-003c,2”, “0|MacroExit|”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: ExecIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: ExecIf
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:21] GotoIf(“Local/107@from-queue-003c,2”, “0?s-BUSY|1”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:21] GotoIf(“Local/107@from-queue-003c,2”, “0?s-BUSY|1”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:22] Macro(“Local/107@from-queue-003c,2”, “vm|107|BUSY|”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-exten-vm:22] Macro(“Local/107@from-queue-003c,2”, “vm|107|BUSY|”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-vm:1] Macro(“Local/107@from-queue-003c,2”, “user-callerid|SKIPTTL”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-vm:1] Macro(“Local/107@from-queue-003c,2”, “user-callerid|SKIPTTL”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-user-callerid:1] Set(“Local/107@from-queue-003c,2”, “AMPUSER=016877777”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-user-callerid:1] Set(“Local/107@from-queue-003c,2”, “AMPUSER=016877777”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“Local/107@from-queue-003c,2”, “1?report”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“Local/107@from-queue-003c,2”, “1?report”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Goto (macro-user-callerid,s,12)
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Goto (macro-user-callerid,s,12)
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-user-callerid:12] GotoIf(“Local/107@from-queue-003c,2”, “1?continue”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-user-callerid:12] GotoIf(“Local/107@from-queue-003c,2”, “1?continue”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Goto (macro-user-callerid,s,25)
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Goto (macro-user-callerid,s,25)
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-user-callerid:25] Set(“Local/107@from-queue-003c,2”, “CALLERID(number)=016877777”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-user-callerid:25] Set(“Local/107@from-queue-003c,2”, “CALLERID(number)=016877777”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-user-callerid:26] Set(“Local/107@from-queue-003c,2”, “CALLERID(name)=M0:Brian “) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-user-callerid:26] Set(“Local/107@from-queue-003c,2”, “CALLERID(name)=M0:Brian “) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Macro
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Macro
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-vm:2] Set(“Local/107@from-queue-003c,2”, “VMGAIN=”””) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-vm:2] Set(“Local/107@from-queue-003c,2”, “VMGAIN=”””) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-vm:3] Macro(“Local/107@from-queue-003c,2”, “blkvm-check|”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-vm:3] Macro(“Local/107@from-queue-003c,2”, “blkvm-check|”) in new stack
[2011-03-14 13:10:37] WARNING[3758] app_macro.c: Context ‘macro-blkvm-check’ for macro ‘blkvm-check’ lacks ‘s’ extension, priority 1
[2011-03-14 13:10:37] WARNING[3758] app_macro.c: Context ‘macro-blkvm-check’ for macro ‘blkvm-check’ lacks ‘s’ extension, priority 1
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Macro
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Macro
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-vm:4] GotoIf(“Local/107@from-queue-003c,2”, “1?vmx|1”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-vm:4] GotoIf(“Local/107@from-queue-003c,2”, “1?vmx|1”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Goto (macro-vm,vmx,1)
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Goto (macro-vm,vmx,1)
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:1] Set(“Local/107@from-queue-003c,2”, “MEXTEN=107”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:1] Set(“Local/107@from-queue-003c,2”, “MEXTEN=107”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:2] Set(“Local/107@from-queue-003c,2”, “MMODE=BUSY”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:2] Set(“Local/107@from-queue-003c,2”, “MMODE=BUSY”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:3] Set(“Local/107@from-queue-003c,2”, “RETVM=”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:3] Set(“Local/107@from-queue-003c,2”, “RETVM=”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:4] Set(“Local/107@from-queue-003c,2”, “MODE=busy”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:4] Set(“Local/107@from-queue-003c,2”, “MODE=busy”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] func_db.c: DB: AMPUSER/107/vmx/busy/state not found in database.
[2011-03-14 13:10:37] DEBUG[3758] func_db.c: DB: AMPUSER/107/vmx/busy/state not found in database.
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:5] GotoIf(“Local/107@from-queue-003c,2”, “1?chknomsg”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:5] GotoIf(“Local/107@from-queue-003c,2”, “1?chknomsg”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Goto (macro-vm,vmx,8)
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Goto (macro-vm,vmx,8)
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:8] GotoIf(“Local/107@from-queue-003c,2”, “0?s-BUSY|1”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:8] GotoIf(“Local/107@from-queue-003c,2”, “0?s-BUSY|1”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:9] GotoIf(“Local/107@from-queue-003c,2”, “1?notdirect”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:9] GotoIf(“Local/107@from-queue-003c,2”, “1?notdirect”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Goto (macro-vm,vmx,11)
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Goto (macro-vm,vmx,11)
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] DEBUG[3758] func_db.c: DB: AMPUSER/107/vmx/busy/state not found in database.
[2011-03-14 13:10:37] DEBUG[3758] func_db.c: DB: AMPUSER/107/vmx/busy/state not found in database.
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:11] NoOp(“Local/107@from-queue-003c,2”, "Checking if ext 107 is enabled: ") in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:11] NoOp(“Local/107@from-queue-003c,2”, "Checking if ext 107 is enabled: ") in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Noop
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Noop
[2011-03-14 13:10:37] DEBUG[3758] func_db.c: DB: AMPUSER/107/vmx/busy/state not found in database.
[2011-03-14 13:10:37] DEBUG[3758] func_db.c: DB: AMPUSER/107/vmx/busy/state not found in database.
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:12] GotoIf(“Local/107@from-queue-003c,2”, “1?s-BUSY|1”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [vmx@macro-vm:12] GotoIf(“Local/107@from-queue-003c,2”, “1?s-BUSY|1”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Goto (macro-vm,s-BUSY,1)
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Goto (macro-vm,s-BUSY,1)
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s-BUSY@macro-vm:1] NoOp(“Local/107@from-queue-003c,2”, “BUSY voicemail”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s-BUSY@macro-vm:1] NoOp(“Local/107@from-queue-003c,2”, “BUSY voicemail”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Noop
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Noop
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s-BUSY@macro-vm:2] Macro(“Local/107@from-queue-003c,2”, “get-vmcontext|107”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s-BUSY@macro-vm:2] Macro(“Local/107@from-queue-003c,2”, “get-vmcontext|107”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-get-vmcontext:1] Set(“Local/107@from-queue-003c,2”, “VMCONTEXT=default”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-get-vmcontext:1] Set(“Local/107@from-queue-003c,2”, “VMCONTEXT=default”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Set
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-get-vmcontext:2] GotoIf(“Local/107@from-queue-003c,2”, “0?200:300”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-get-vmcontext:2] GotoIf(“Local/107@from-queue-003c,2”, “0?200:300”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Goto (macro-get-vmcontext,s,300)
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Goto (macro-get-vmcontext,s,300)
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-get-vmcontext:300] NoOp(“Local/107@from-queue-003c,2”, “”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s@macro-get-vmcontext:300] NoOp(“Local/107@from-queue-003c,2”, “”) in new stack
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: NoOp
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: NoOp
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Macro
[2011-03-14 13:10:37] DEBUG[3758] app_macro.c: Executed application: Macro
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s-BUSY@macro-vm:3] VoiceMail(“Local/107@from-queue-003c,2”, “107@default|b”) in new stack
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – Executing [s-BUSY@macro-vm:3] VoiceMail(“Local/107@from-queue-003c,2”, “107@default|b”) in new stack
[2011-03-14 13:10:37] VERBOSE[3754] logger.c: – Local/107@from-queue-003c,1 answered DAHDI/9-1
[2011-03-14 13:10:37] VERBOSE[3754] logger.c: – Local/107@from-queue-003c,1 answered DAHDI/9-1
[2011-03-14 13:10:37] VERBOSE[3754] logger.c: – Stopped music on hold on DAHDI/9-1
[2011-03-14 13:10:37] VERBOSE[3754] logger.c: – Stopped music on hold on DAHDI/9-1
[2011-03-14 13:10:37] WARNING[3754] app_queue.c: The device state of this queue member, Local/107@from-queue/n, is still ‘Not in Use’ when it probably should not be! Please check UPGRADE.txt for correct configuration settings.
[2011-03-14 13:10:37] WARNING[3754] app_queue.c: The device state of this queue member, Local/107@from-queue/n, is still ‘Not in Use’ when it probably should not be! Please check UPGRADE.txt for correct configuration settings.
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – <Local/107@from-queue-003c,2> Playing ‘vm-theperson’ (language ‘en’)
[2011-03-14 13:10:37] VERBOSE[3758] logger.c: – <Local/107@from-queue-003c,2> Playing ‘vm-theperson’ (language ‘en’)
[2011-03-14 13:10:39] VERBOSE[3758] logger.c: – <Local/107@from-queue-003c,2> Playing ‘digits/1’ (language ‘en’)
[2011-03-14 13:10:39] VERBOSE[3758] logger.c: – <Local/107@from-queue-003c,2> Playing ‘digits/1’ (language ‘en’)
[2011-03-14 13:10:39] VERBOSE[3743] logger.c: – Remote UNIX connection disconnected
[2011-03-14 13:10:39] VERBOSE[3743] logger.c: – Remote UNIX connection disconnected
[2011-03-14 13:10:39] VERBOSE[23185] logger.c: – Channel 0/9, span 1 got hangup request, cause 0
[2011-03-14 13:10:39] VERBOSE[23185] logger.c: – Channel 0/9, span 1 got hangup request, cause 0
[2011-03-14 13:10:39] VERBOSE[3758] logger.c: – <Local/107@from-queue-003c,2> Playing ‘digits/0’ (language ‘en’)
[2011-03-14 13:10:39] VERBOSE[3758] logger.c: – <Local/107@from-queue-003c,2> Playing ‘digits/0’ (language ‘en’)
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: == Spawn extension (ext-queues, 400, 10) exited non-zero on ‘DAHDI/9-1’
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: == Spawn extension (ext-queues, 400, 10) exited non-zero on ‘DAHDI/9-1’
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Executing [h@ext-queues:1] Macro(“DAHDI/9-1”, “hangupcall|”) in new stack
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Executing [h@ext-queues:1] Macro(“DAHDI/9-1”, “hangupcall|”) in new stack
[2011-03-14 13:10:39] VERBOSE[3758] logger.c: == Spawn extension (macro-vm, s-BUSY, 3) exited non-zero on ‘Local/107@from-queue-003c,2’ in macro ‘vm’
[2011-03-14 13:10:39] VERBOSE[3758] logger.c: == Spawn extension (macro-vm, s-BUSY, 3) exited non-zero on ‘Local/107@from-queue-003c,2’ in macro ‘vm’
[2011-03-14 13:10:39] VERBOSE[3758] logger.c: == Spawn extension (macro-vm, s-BUSY, 3) exited non-zero on ‘Local/107@from-queue-003c,2’ in macro ‘exten-vm’
[2011-03-14 13:10:39] VERBOSE[3758] logger.c: == Spawn extension (macro-vm, s-BUSY, 3) exited non-zero on ‘Local/107@from-queue-003c,2’ in macro ‘exten-vm’
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Executing [s@macro-hangupcall:1] GotoIf(“DAHDI/9-1”, “1?skiprg”) in new stack
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Executing [s@macro-hangupcall:1] GotoIf(“DAHDI/9-1”, “1?skiprg”) in new stack
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Goto (macro-hangupcall,s,3)
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Goto (macro-hangupcall,s,3)
[2011-03-14 13:10:39] DEBUG[3754] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:39] DEBUG[3754] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Executing [s@macro-hangupcall:3] GotoIf(“DAHDI/9-1”, “1?skipblkvm”) in new stack
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Executing [s@macro-hangupcall:3] GotoIf(“DAHDI/9-1”, “1?skipblkvm”) in new stack
[2011-03-14 13:10:39] VERBOSE[3758] logger.c: == Spawn extension (macro-vm, s-BUSY, 3) exited non-zero on ‘Local/107@from-queue-003c,2’
[2011-03-14 13:10:39] VERBOSE[3758] logger.c: == Spawn extension (macro-vm, s-BUSY, 3) exited non-zero on ‘Local/107@from-queue-003c,2’
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Goto (macro-hangupcall,s,5)
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Goto (macro-hangupcall,s,5)
[2011-03-14 13:10:39] DEBUG[3754] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:39] DEBUG[3754] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Executing [s@macro-hangupcall:5] GotoIf(“DAHDI/9-1”, “1?theend”) in new stack
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Executing [s@macro-hangupcall:5] GotoIf(“DAHDI/9-1”, “1?theend”) in new stack
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Goto (macro-hangupcall,s,7)
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Goto (macro-hangupcall,s,7)
[2011-03-14 13:10:39] DEBUG[3754] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:39] DEBUG[3754] app_macro.c: Executed application: GotoIf
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Executing [s@macro-hangupcall:7] Hangup(“DAHDI/9-1”, “”) in new stack
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: – Executing [s@macro-hangupcall:7] Hangup(“DAHDI/9-1”, “”) in new stack
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: == Spawn extension (macro-hangupcall, s, 7) exited non-zero on ‘DAHDI/9-1’ in macro ‘hangupcall’
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: == Spawn extension (macro-hangupcall, s, 7) exited non-zero on ‘DAHDI/9-1’ in macro ‘hangupcall’
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: == Spawn extension (macro-hangupcall, s, 7) exited non-zero on ‘DAHDI/9-1’
[2011-03-14 13:10:39] VERBOSE[3754] logger.c: == Spawn extension (macro-hangupcall, s, 7) exited non-zero on ‘DAHDI/9-1’
[2011-03-14 13:10:39] DEBUG[3754] chan_dahdi.c: Set option AUDIO MODE, value: ON(1) on DAHDI/9-1
[2011-03-14 13:10:39] DEBUG[3754] chan_dahdi.c: Set option AUDIO MODE, value: ON(1) on DAHDI/9-1
[2011-03-14 13:10:39] DEBUG[3754] chan_dahdi.c: Not yet hungup… Calling hangup once with icause, and clearing call
[2011-03-14 13:10:39] DEBUG[3754] chan_dahdi.c: Not yet hungup… Calling hangup once with icause, and clearing call
[2011-03-14 13:10:39] DEBUG[3754] chan_dahdi.c: Set option AUDIO MODE, value: OFF(0) on DAHDI/9-1
[2011-03-14 13:10:39] DEBUG[3754] chan_dahdi.c: Set option AUDIO MODE, value: OFF(0) on DAHDI/9-1

plindheimer · March 14, 2011, 3:13pm

Something looks wrong here:

-- Executing [s@macro-vm:3] Macro("Local/107@from-queue-003c,2", "blkvm-check|") in new stack

It should go to that macro and check if voicemail should be left, it is skipping right over it. Please check your logs and see if there is an error and it is not finding that macro and what the error is saying.

(There’s a corresponding macro-blkvm-set called before the client enters the queue that sets a shared flag so that the dialplan would know not to drop into voicemail.)

So make sure core is completely up-to-date, and then check what is happening wrt to that macro because all indications are that it is not there and it should be.